niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #442
· 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.10s)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 119 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.71s)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 TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestFileTokenEmpty137=== CONT TestFileTokenReadsAndCaches138=== CONT TestParsePathInfoJSONMultiplePaths139=== CONT TestUploadMultipart_SupersededByPeer140=== RUN TestUploadMultipart_SupersededByPeer/exists141=== CONT TestScriptTokenBadJSON142=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry143=== CONT TestScriptTokenNoExpiryRerunsEveryCall144=== CONT TestStaticToken145=== CONT TestSetClientTLSErrors146=== CONT TestClientSignaturesByStorePath147=== CONT TestCompletePendingClosure_NotFoundWithoutKey148=== CONT TestDoWithRetry_BodyReplayedViaGetBody149=== CONT TestScriptTokenDoesNotWaitForItsChildren150=== CONT TestScriptTokenScriptFails151=== CONT TestPathInfoHashCompatibility152=== CONT TestStreamPushBatchesUnderLoad153=== CONT TestGetStorePathHash154=== CONT TestSetClientTLS155=== CONT TestParsePathInfoJSON156=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel157=== CONT TestConvertHashToNix32158=== CONT TestStreamPushReportsEveryPath159=== CONT TestEncodeNixBase32WithRealHash160=== CONT TestStreamPushStopsOnCancel161=== CONT TestShellSplit162=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer163=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== CONT TestFileTokenMissing165=== PAUSE TestUploadMultipart_SupersededByPeer/exists166--- PASS: TestFileTokenReadsAndCaches (0.00s)167=== CONT TestTruncatedNARDumpIsNotCompleted168=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs169=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false171=== RUN TestGetStorePathHash/valid_store_path172=== RUN TestParsePathInfoJSON/Nix_format173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestStreamPushStopsOnCancel/waiting_for_input175=== CONT TestStreamPushGivesUpOnDeadServer176--- PASS: TestStaticToken (0.00s)177=== RUN TestUploadMultipart_SupersededByPeer/missing178=== CONT TestRetryTimeoutOutlastsMaxRetries179=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32180=== RUN TestConvertHashToNix32/already_Nix32_format181=== PAUSE TestGetStorePathHash/valid_store_path182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs185=== CONT TestUploadMultipart_FailedPartBufferNotReused186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)187=== PAUSE TestParsePathInfoJSON/Nix_format188=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false189--- PASS: TestFileTokenEmpty (0.00s)190--- PASS: TestClientSignaturesByStorePath (0.00s)191=== PAUSE TestConvertHashToNix32/already_Nix32_format192=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error193=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input194=== CONT TestDumpPathSingleFile195=== CONT TestSetClientTLSDoesNotMutateDefaultTransport196=== PAUSE TestUploadMultipart_SupersededByPeer/missing197=== CONT TestShellSplitErrors198=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon200=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout201=== CONT TestEncodeNixBase32202=== RUN TestSetClientTLSErrors/missing_cert_file203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== RUN TestParsePathInfoJSON/Lix_format205=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true206--- PASS: TestEncodeNixBase32WithRealHash (0.02s)207--- PASS: TestFileTokenMissing (0.00s)208--- PASS: TestScriptTokenBadJSON (0.19s)209=== RUN TestEncodeNixBase32/test_string_hash210=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true211=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent212=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA215=== PAUSE TestEncodeNixBase32/test_string_hash216=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier217=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up218=== CONT TestDoWithRetry_FinalResponseBodyReadable219=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA220=== RUN TestEncodeNixBase32/empty_input221=== RUN TestSetClientTLS/preserves_debug_logging_transport222=== PAUSE TestParsePathInfoJSON/Lix_format223=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess224=== CONT TestStreamPushStopsWhenCanceled225=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error226=== PAUSE TestEncodeNixBase32/empty_input227=== CONT TestDumpPathMatchesNix228=== CONT TestDumpPathWriterError229=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout230=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon231=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI232=== PAUSE TestSetClientTLSErrors/missing_cert_file233=== CONT TestScriptTokenEmptyToken234=== CONT TestScriptTokenEmptyCommand235=== CONT TestStreamPushReportsSignatures236=== RUN TestSetClientTLSErrors/missing_key_file237=== RUN TestConvertHashToNix32/invalid_format238--- PASS: TestShellSplit (0.16s)239=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up240=== CONT TestResolveStorePath241=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier242=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier243=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client244=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client245=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client246=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client247=== CONT TestSupersededNARStillUploadsListing248=== RUN TestSupersededNARStillUploadsListing/small_NAR249=== PAUSE TestSupersededNARStillUploadsListing/small_NAR250=== RUN TestSupersededNARStillUploadsListing/dump_cut_short251=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short252=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails253=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails254=== CONT TestRegisterUploadedObjectReusesConnections255=== CONT TestStreamPushRequestLine256=== CONT TestRateLimiterFeedback257=== RUN TestRateLimiterFeedback/429_enables_limiter258=== PAUSE TestRateLimiterFeedback/429_enables_limiter259=== RUN TestParsePathInfoJSON/empty_input260=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths261=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error262=== PAUSE TestParsePathInfoJSON/empty_input263=== RUN TestParsePathInfoJSON/whitespace_only264=== CONT TestUploadMultipart_PartsInParallel265=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error266=== PAUSE TestParsePathInfoJSON/whitespace_only267=== PAUSE TestSetClientTLS/preserves_debug_logging_transport268=== CONT TestPartSizeForNAR269=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot270=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI271--- PASS: TestScriptTokenScriptFails (0.19s)272=== PAUSE TestConvertHashToNix32/invalid_format273=== PAUSE TestSetClientTLSErrors/missing_key_file274=== RUN TestRateLimiterFeedback/503_enables_limiter275=== CONT TestPathInfoCACompatibility276=== CONT TestUploadMultipart_ProducerErrorIsNotEOF277=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun278=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error279=== RUN TestParsePathInfoJSON/invalid_JSON280=== RUN TestPartSizeForNAR/zero_stays_at_minimum281=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512282=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot283--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.19s)284=== CONT TestScriptTokenCachesUntilRefresh285=== RUN TestSetClientTLSErrors/missing_ca_file286=== RUN TestPathInfoCACompatibility/null_ca_field287=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica288=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part289=== PAUSE TestRateLimiterFeedback/503_enables_limiter290=== PAUSE TestParsePathInfoJSON/invalid_JSON291=== CONT TestCaseHackSuffix292=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot293=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum294=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512295--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.46s)296=== PAUSE TestSetClientTLSErrors/missing_ca_file297=== PAUSE TestPathInfoCACompatibility/null_ca_field298=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part299=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure300=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot301=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot302=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot303=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot304=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot305=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken306=== RUN TestPathInfoCACompatibility/old_string_format_-_text307=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text308=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive309=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive310=== RUN TestPathInfoCACompatibility/new_structured_format_-_text311=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text312=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method314=== CONT TestDoServerRequestAttachesToken315=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary316=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken317=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary318=== CONT TestStreamPushReportsSkippedPaths319=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter320=== CONT TestFilterOversizedClosures321--- PASS: TestStreamPushReportsEveryPath (0.46s)322=== CONT TestStreamPushIsolatesFailures323=== RUN TestSetClientTLSErrors/invalid_ca_file324=== RUN TestFilterOversizedClosures/no_limit_keeps_everything325--- PASS: TestShellSplitErrors (0.00s)326=== PAUSE TestSetClientTLSErrors/invalid_ca_file327=== CONT TestUploadMultipart_SupersededByPeer/exists328=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false329=== RUN TestPartSizeForNAR/small_stays_at_minimum330=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter331=== PAUSE TestPartSizeForNAR/small_stays_at_minimum332=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter333=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum334=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything335--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.46s)336=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true337--- PASS: TestStreamPushGivesUpOnDeadServer (0.27s)338--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.47s)339=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter340--- PASS: TestStreamPushStopsWhenCanceled (0.00s)341--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)342=== CONT TestEncodeNixBase32/test_string_hash343=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum344=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped345=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout346=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped347=== CONT TestUploadMultipart_SupersededByPeer/missing348--- PASS: TestScriptTokenEmptyCommand (0.00s)349=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts350=== CONT TestEncodeNixBase32/empty_input351=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts352=== RUN TestPartSizeForNAR/1_TiB353=== PAUSE TestPartSizeForNAR/1_TiB354=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client355=== RUN TestFilterOversizedClosures/all_closures_skipped356=== PAUSE TestFilterOversizedClosures/all_closures_skipped357--- PASS: TestResolveStorePath (0.00s)358=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier359=== RUN TestPartSizeForNAR/5_TiB_S3_max_object360=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client361=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up362--- PASS: TestStreamPushReportsSignatures (0.01s)363=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object364--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)365=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier366=== RUN TestPartSizeForNAR/capped_at_5_GiB367=== PAUSE TestPartSizeForNAR/capped_at_5_GiB368--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)369--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)370=== CONT TestSupersededNARStillUploadsListing/dump_cut_short371--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)372=== CONT TestSupersededNARStillUploadsListing/small_NAR373=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails374=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs375--- PASS: TestStreamPushReportsSkippedPaths (0.00s)376--- PASS: TestStreamPushIsolatesFailures (0.00s)377--- PASS: TestDoServerRequestAttachesToken (0.00s)378=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths379--- PASS: TestStreamPushBatchesUnderLoad (0.46s)380 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)381 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)382--- PASS: TestScriptTokenEmptyToken (0.02s)383--- PASS: TestEncodeNixBase32 (0.00s)384 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)385 --- PASS: TestEncodeNixBase32/empty_input (0.00s)386--- PASS: TestUploadMultipart_SupersededByPeer (0.46s)387 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)388 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)389=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths390=== CONT TestSetClientTLS/preserves_debug_logging_transport391--- PASS: TestParsePathInfoJSONMultiplePaths (0.48s)392 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)393 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)394=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA395=== CONT TestSetClientTLS/rejects_connection_without_client_cert396=== CONT TestConvertHashToNix32/invalid_format397=== CONT TestConvertHashToNix32/already_Nix32_format398--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)399 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)400 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)401 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)402 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)403 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)404=== CONT TestConvertHashToNix32/SRI_format_to_Nix32405=== CONT TestGetStorePathHash/basename_without_hyphen_should_error406=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error407--- PASS: TestConvertHashToNix32 (0.63s)408 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)409 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)410 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)411=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error412=== CONT TestGetStorePathHash/valid_store_path413=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)414=== CONT TestParsePathInfoJSON/invalid_JSON415--- PASS: TestGetStorePathHash (0.75s)416 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)417 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)418 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)419 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)420=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512421=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI422=== CONT TestParsePathInfoJSON/whitespace_only423=== CONT TestParsePathInfoJSON/empty_input424=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon425=== CONT TestParsePathInfoJSON/Lix_format426--- PASS: TestPathInfoHashCompatibility (0.76s)427 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)428 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)429 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)430 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)431--- PASS: TestDumpPathSingleFile (0.31s)432=== CONT TestPathInfoCACompatibility/old_string_format_-_text433=== CONT TestParsePathInfoJSON/Nix_format434=== CONT TestStreamPushStopsOnCancel/waiting_for_input435=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method436=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot437=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken438--- PASS: TestParsePathInfoJSON (0.75s)439 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)440 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)441 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)442 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)443 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)444--- PASS: TestCaseHackSuffix (0.29s)445=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive446=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot447=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot448--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.18s)449=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot450=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part451=== CONT TestPathInfoCACompatibility/new_structured_format_-_text452=== CONT TestPathInfoCACompatibility/null_ca_field453=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary454=== CONT TestSetClientTLSErrors/missing_key_file455=== CONT TestSetClientTLSErrors/missing_ca_file456--- PASS: TestPathInfoCACompatibility (0.13s)457 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)458 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)459 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)460 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)461 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)462=== CONT TestSetClientTLSErrors/invalid_ca_file463=== CONT TestSetClientTLSErrors/missing_cert_file464=== CONT TestRateLimiterFeedback/503_enables_limiter465--- PASS: TestSetClientTLSErrors (0.76s)466 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)467 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)468 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)469 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)470=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter471=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter472=== CONT TestRateLimiterFeedback/429_enables_limiter473=== CONT TestFilterOversizedClosures/all_closures_skipped474=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped475=== CONT TestFilterOversizedClosures/no_limit_keeps_everything476=== CONT TestPartSizeForNAR/zero_stays_at_minimum477=== CONT TestPartSizeForNAR/1_TiB478--- PASS: TestFilterOversizedClosures (0.00s)479 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.01s)480 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)481 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.01s)482=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts483=== CONT TestPartSizeForNAR/5_TiB_S3_max_object484=== CONT TestPartSizeForNAR/capped_at_5_GiB485=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum486--- PASS: TestRetryTimeoutOutlastsMaxRetries (1.04s)487=== CONT TestPartSizeForNAR/small_stays_at_minimum488--- PASS: TestPartSizeForNAR (0.28s)489 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)490 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)491 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)492 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)493 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)494 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)495 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)496--- PASS: TestRateLimiterFeedback (0.29s)497 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)498 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)499 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)500 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)501--- PASS: TestStreamPushStopsOnCancel (0.74s)502 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.43s)503 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.43s)504 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.43s)505 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)508--- PASS: TestDumpPathWriterError (0.79s)509--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (1.30s)510--- PASS: TestSetClientTLS (0.48s)511 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.44s)512 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.47s)513 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.55s)514--- PASS: TestRegisterUploadedObjectReusesConnections (0.91s)515--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)516 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.18s)517 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.19s)518--- PASS: TestStreamPushRequestLine (0.94s)519--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)520--- PASS: TestSupersededNARStillUploadsListing (0.00s)521 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.46s)522 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.46s)523 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.14s)524--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.74s)525--- PASS: TestUploadMultipart_PartsInParallel (1.51s)526--- PASS: TestTruncatedNARDumpIsNotCompleted (1.90s)527--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (1.59s)528--- PASS: TestDumpPathMatchesNix (1.93s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.46s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.28s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "nixbld".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /build/postgres2428780684/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.556557Success. You can now start the database server using:558559 pg_ctl -D /build/postgres2428780684/data -l logfile start560561/build/postgres2428780684:5432 - no response5622026-10-27 08:51:01.372 UTC [171] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-27 08:51:01.372 UTC [171] LOG: listening on Unix socket "/build/postgres2428780684/.s.PGSQL.5432"5642026-10-27 08:51:01.377 UTC [178] LOG: database system was shut down at 2026-10-27 08:51:01 UTC5652026-10-27 08:51:01.381 UTC [171] LOG: database system is ready to accept connections566/build/postgres2428780684:5432 - accepting connections567{"timestamp":"2026-10-27T08:51:03.120228498Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4788ba26-11fb-4b98-9658-da24ab1f866f","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":5,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}568=== RUN TestService_AuthMiddleware569=== PAUSE TestService_AuthMiddleware570=== RUN TestService_AuthMiddleware_MTLSProxyHeader571=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader572=== RUN TestService_AuthMiddleware_MTLSBoundSubjects573=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects574=== RUN TestService_ReadAuthMiddleware575=== PAUSE TestService_ReadAuthMiddleware576=== RUN TestService_AuthMiddleware_OIDC577=== PAUSE TestService_AuthMiddleware_OIDC578=== RUN TestService_RequireScope_OIDC579=== PAUSE TestService_RequireScope_OIDC580=== RUN TestService_ReadScope_PublicByDefault581=== PAUSE TestService_ReadScope_PublicByDefault582=== RUN TestCacheConfigHandler583=== PAUSE TestCacheConfigHandler584=== RUN TestCacheStatsHandler585=== PAUSE TestCacheStatsHandler586=== RUN TestClientCADerivations587=== PAUSE TestClientCADerivations588=== RUN TestClientErrorHandling589=== PAUSE TestClientErrorHandling590=== RUN TestClientIntegration591=== PAUSE TestClientIntegration592=== RUN TestClientMultipleUploads593=== PAUSE TestClientMultipleUploads594=== RUN TestClientWithDependencies595=== PAUSE TestClientWithDependencies596=== RUN TestClientSharedPathCommittedMidPush597=== PAUSE TestClientSharedPathCommittedMidPush598=== RUN TestPinProtectsFromGC599=== PAUSE TestPinProtectsFromGC600=== RUN TestClientPushesUseOnePush601=== PAUSE TestClientPushesUseOnePush602=== RUN TestClientFallsBackToClosures603=== PAUSE TestClientFallsBackToClosures604=== RUN TestDeleteClosuresRacingPins605=== PAUSE TestDeleteClosuresRacingPins606=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock607=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== RUN TestResolveDBConnectionString609=== PAUSE TestResolveDBConnectionString610=== RUN TestConnectWaitsForAPeerMigration611=== PAUSE TestConnectWaitsForAPeerMigration612=== RUN TestConnectSerialisesConcurrentMigrations613=== PAUSE TestConnectSerialisesConcurrentMigrations614=== RUN TestLeadElectsOneAndHandsOver615=== PAUSE TestLeadElectsOneAndHandsOver616=== RUN TestLeadIncumbentWinsAfterRestart6172026/10/27 08:51:03 INFO lead: acquired remote=192.0.2.1:12346182026/10/27 08:51:04 INFO lead: released remote=192.0.2.1:12346192026/10/27 08:51:04 INFO lead: acquired remote=192.0.2.1:12346202026/10/27 08:51:05 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (2.18s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/27 08:51:05 INFO lead: acquired remote=192.0.2.1:12346282026-10-27 08:51:07.036 UTC [429] FATAL: terminating connection due to administrator command6292026/10/27 08:51:07 INFO lead: acquired remote=192.0.2.1:12346302026/10/27 08:51:08 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/27 08:51:08 INFO lead: released remote=192.0.2.1:12346322026/10/27 08:51:08 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (3.05s)634=== RUN TestGCAdvisoryLockBlocksConcurrentRun635=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun636=== RUN TestGCBugBareHashReferences637=== PAUSE TestGCBugBareHashReferences638=== RUN TestGCMetrics639=== PAUSE TestGCMetrics640=== RUN TestPushDedupSurvivesConcurrentGC641=== PAUSE TestPushDedupSurvivesConcurrentGC642=== RUN TestDeduplicatedObjectsRecordedAsPending643=== PAUSE TestDeduplicatedObjectsRecordedAsPending644=== RUN TestGCSweepSkipsPendingObjects645=== PAUSE TestGCSweepSkipsPendingObjects646=== RUN TestTombstonedObjectOfferedWithoutWaiting647=== PAUSE TestTombstonedObjectOfferedWithoutWaiting648=== RUN TestGCSweepDeliversEachKeyOnce649=== PAUSE TestGCSweepDeliversEachKeyOnce650=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection651=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== RUN TestForceGCDuringPushOffersSweptObject653=== PAUSE TestForceGCDuringPushOffersSweptObject654=== RUN TestFailedS3DeleteKeepsTombstone655=== PAUSE TestFailedS3DeleteKeepsTombstone656=== RUN TestSweepSkipsRowsLockedByPush657=== PAUSE TestSweepSkipsRowsLockedByPush658=== RUN TestRegisterCompletedObjectNeedsPendingRow659=== PAUSE TestRegisterCompletedObjectNeedsPendingRow660=== RUN TestGetExistingObjectsLocksRows661=== PAUSE TestGetExistingObjectsLocksRows662=== RUN TestSweepRechecksPendingAfterLocking663=== PAUSE TestSweepRechecksPendingAfterLocking664=== RUN TestPushWaitsForSweepHoldingRow665=== PAUSE TestPushWaitsForSweepHoldingRow666=== RUN TestCommitRacingPendingCleanupKeepsObjects667=== PAUSE TestCommitRacingPendingCleanupKeepsObjects668=== RUN TestGCEndsOnShutdown669=== PAUSE TestGCEndsOnShutdown670=== RUN TestGCTaskStore_StartNew671=== PAUSE TestGCTaskStore_StartNew672=== RUN TestGCTaskStore_DeduplicateSameParams673=== PAUSE TestGCTaskStore_DeduplicateSameParams674=== RUN TestGCTaskStore_ConflictDifferentParams675=== PAUSE TestGCTaskStore_ConflictDifferentParams676=== RUN TestGCTaskStore_GetEmpty677=== PAUSE TestGCTaskStore_GetEmpty678=== RUN TestGCTaskStore_GetReturnsLatest679=== PAUSE TestGCTaskStore_GetReturnsLatest680=== RUN TestGCTaskStore_CompletedAllowsNewTask681=== PAUSE TestGCTaskStore_CompletedAllowsNewTask682=== RUN TestGCTaskStore_PhaseUpdates683=== PAUSE TestGCTaskStore_PhaseUpdates684=== RUN TestGCTaskStore_Fail685=== PAUSE TestGCTaskStore_Fail686=== RUN TestGracefulShutdownDrainsInflight687=== PAUSE TestGracefulShutdownDrainsInflight688=== RUN TestService_healthCheckHandler689=== PAUSE TestService_healthCheckHandler690=== RUN TestService_readinessHandler691=== PAUSE TestService_readinessHandler692=== RUN TestGenerateLandingPage693=== PAUSE TestGenerateLandingPage694=== RUN TestChildrenInheritRaisedFileLimit695=== PAUSE TestChildrenInheritRaisedFileLimit696=== RUN TestCacheConfigHandlerMaxNarSize697=== PAUSE TestCacheConfigHandlerMaxNarSize698=== RUN TestCreatePendingClosureRejectsOversizedNAR699=== PAUSE TestCreatePendingClosureRejectsOversizedNAR700=== RUN TestNARDeduplicationMetadataUploadBug701=== PAUSE TestNARDeduplicationMetadataUploadBug702=== RUN TestMetricsInventory703=== PAUSE TestMetricsInventory704=== RUN TestMetricsCommit705=== PAUSE TestMetricsCommit706=== RUN TestService_NativeMTLS707=== PAUSE TestService_NativeMTLS708=== RUN TestServerTLSConfig709=== PAUSE TestServerTLSConfig710=== RUN TestMultipartCleanup711=== PAUSE TestMultipartCleanup712=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded713=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== RUN TestPendingCleanupUsesOneCutoff715=== PAUSE TestPendingCleanupUsesOneCutoff716=== RUN TestPendingClosureFailureTracksEveryUpload717=== PAUSE TestPendingClosureFailureTracksEveryUpload718=== RUN TestPendingClosureFailureAbortsItsUploads719=== PAUSE TestPendingClosureFailureAbortsItsUploads720=== RUN TestObjectStatsTrigger721=== PAUSE TestObjectStatsTrigger722=== RUN TestObjectStatsUpdatedOncePerCommit723=== PAUSE TestObjectStatsUpdatedOncePerCommit724=== RUN TestReconnectLeavesObjectsUnlocked725=== PAUSE TestReconnectLeavesObjectsUnlocked726=== RUN TestOrphanedObjectsGC727=== PAUSE TestOrphanedObjectsGC728=== RUN TestOrphanedObjectsGCStressTest729=== PAUSE TestOrphanedObjectsGCStressTest730=== RUN TestCreatePin_ReservedPins731=== PAUSE TestCreatePin_ReservedPins732=== RUN TestConcurrentPinUpdatesAgree733=== PAUSE TestConcurrentPinUpdatesAgree734=== RUN TestCreatePinRejectsBadInput735=== PAUSE TestCreatePinRejectsBadInput736=== RUN TestDeletePinKeepsRowWhenS3Fails737=== PAUSE TestDeletePinKeepsRowWhenS3Fails738=== RUN TestPresentReportsOnlyClosureRoots739=== PAUSE TestPresentReportsOnlyClosureRoots740=== RUN TestPresentRefreshesOnlyStaleClosures741=== PAUSE TestPresentRefreshesOnlyStaleClosures742=== RUN TestPresentNotReportedWhileGCDeletesClosure743=== PAUSE TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestParseSingleRange745=== PAUSE TestParseSingleRange746=== RUN TestProxyHeadersOnlyTrustedOnSocket7472026/10/27 08:51:08 INFO Starting HTTP server address=proxy.sock7482026/10/27 08:51:08 INFO Starting HTTP server address=127.0.0.1:436677492026/10/27 08:51:08 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/27 08:51:08 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.27s)752=== RUN TestIsValidCachePath753=== PAUSE TestIsValidCachePath754=== RUN TestReadProxyNarinfo755=== PAUSE TestReadProxyNarinfo756=== RUN TestReadProxyNarinfoAlreadyDecompressed757=== PAUSE TestReadProxyNarinfoAlreadyDecompressed758=== RUN TestReadProxyContentNegotiation759=== PAUSE TestReadProxyContentNegotiation760=== RUN TestReadProxyNarStreaming761=== PAUSE TestReadProxyNarStreaming762=== RUN TestReadProxy404And429763=== PAUSE TestReadProxy404And429764=== RUN TestReadProxyInvalidPath765=== PAUSE TestReadProxyInvalidPath766=== RUN TestReadProxyHead767=== PAUSE TestReadProxyHead768=== RUN TestReadProxyOutlastsServerWriteTimeout769=== PAUSE TestReadProxyOutlastsServerWriteTimeout770=== RUN TestReadProxyConditionalGet771=== PAUSE TestReadProxyConditionalGet772=== RUN TestReadProxyRootRedirectsToIndexHTML773=== PAUSE TestReadProxyRootRedirectsToIndexHTML774=== RUN TestReadProxyDisabled775=== PAUSE TestReadProxyDisabled776=== RUN TestReadRedirectNar777=== PAUSE TestReadRedirectNar778=== RUN TestReadRedirectKeepsNarinfoProxied779=== PAUSE TestReadRedirectKeepsNarinfoProxied780=== RUN TestReadProxyRangeRequest781=== PAUSE TestReadProxyRangeRequest782=== RUN TestReadRedirectUsesPublicS3URL783=== PAUSE TestReadRedirectUsesPublicS3URL784=== RUN TestPush_OverlappingRootsStoreOneRowPerKey785=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey786=== RUN TestPush_CompleteCommitsEveryRoot787=== PAUSE TestPush_CompleteCommitsEveryRoot788=== RUN TestPush_RepeatedRootCommitsOnce789=== PAUSE TestPush_RepeatedRootCommitsOnce790=== RUN TestPush_CompleteWaitsForCleanupOfThePush791=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush792=== RUN TestPush_RootsAreLockedInByteOrder793=== PAUSE TestPush_RootsAreLockedInByteOrder794=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit795=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit796=== RUN TestPush_RejectsBadRequests797=== PAUSE TestPush_RejectsBadRequests798=== RUN TestPush_SignsNarinfosOfItsPendingObjects799=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects800=== RUN TestRedundantMultipartUpload801=== PAUSE TestRedundantMultipartUpload802=== RUN TestCompleteMultipartUpload_ErrorButObjectExists803=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists804=== RUN TestCompletedNarNotReofferedAcrossClosures805=== PAUSE TestCompletedNarNotReofferedAcrossClosures806=== RUN TestPresignedUploadRegisteredBeforeCommit807=== PAUSE TestPresignedUploadRegisteredBeforeCommit808=== RUN TestService_Rustfstest809=== PAUSE TestService_Rustfstest810=== RUN TestParseSize811=== PAUSE TestParseSize812=== RUN TestSkippedUploadsHandler813=== PAUSE TestSkippedUploadsHandler814=== RUN TestSystemdListenerNotActivated815--- PASS: TestSystemdListenerNotActivated (0.00s)816=== RUN TestWatchdogBeatsWhenHealthy817--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)818=== RUN TestWatchdogSkipsWhenUnhealthy8192026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/27 08:51:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"829--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)830=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== RUN TestProxyWriteTimeout833=== PAUSE TestProxyWriteTimeout834=== RUN TestPendingClosureWriteTimeout835=== PAUSE TestPendingClosureWriteTimeout836=== RUN TestIsValidUploadKey837=== PAUSE TestIsValidUploadKey838=== RUN TestUploadHandlersRejectInvalidKeys839=== PAUSE TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectOversizedBody841=== PAUSE TestUploadHandlersRejectOversizedBody842=== RUN TestService_cleanupPendingClosuresHandler843=== PAUSE TestService_cleanupPendingClosuresHandler844=== RUN TestService_createPendingClosureHandler845=== PAUSE TestService_createPendingClosureHandler846=== RUN TestService_verifyS3Integrity847=== PAUSE TestService_verifyS3Integrity848=== RUN TestCompleteMultipartUnregistered849=== PAUSE TestCompleteMultipartUnregistered850=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT851=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT852=== CONT TestService_AuthMiddleware853=== CONT TestMultipartCleanup854=== CONT TestReadProxyRootRedirectsToIndexHTML855=== CONT TestPresignedUploadRegisteredBeforeCommit856=== CONT TestPush_RepeatedRootCommitsOnce857=== CONT TestReadProxyContentNegotiation858=== CONT TestIsValidCachePath859=== RUN TestIsValidCachePath/narinfo860=== PAUSE TestIsValidCachePath/narinfo861=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars862=== CONT TestReadProxyNarinfoAlreadyDecompressed863=== CONT TestPush_SignsNarinfosOfItsPendingObjects864=== CONT TestSweepRechecksPendingAfterLocking865=== CONT TestReadProxyRangeRequest866=== CONT TestCreatePin_ReservedPins867=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars868=== RUN TestIsValidCachePath/nar_zst869=== PAUSE TestIsValidCachePath/nar_zst870=== RUN TestIsValidCachePath/nar_xz871=== PAUSE TestIsValidCachePath/nar_xz872=== RUN TestIsValidCachePath/nar_bz2873=== PAUSE TestIsValidCachePath/nar_bz2874=== RUN TestIsValidCachePath/nar_uncompressed875=== PAUSE TestIsValidCachePath/nar_uncompressed876=== RUN TestIsValidCachePath/ls877=== CONT TestCompleteMultipartUpload_ErrorButObjectExists878=== PAUSE TestIsValidCachePath/ls879=== RUN TestIsValidCachePath/log880=== CONT TestPresentReportsOnlyClosureRoots881=== CONT TestReadRedirectKeepsNarinfoProxied882=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT883=== CONT TestMetricsInventory884=== CONT TestDeletePinKeepsRowWhenS3Fails885=== CONT TestCreatePinRejectsBadInput886=== CONT TestReadProxyNarinfo887=== CONT TestConcurrentPinUpdatesAgree888=== CONT TestReadProxyNarStreaming889=== CONT TestMetricsCommit890=== PAUSE TestIsValidCachePath/log891=== RUN TestIsValidCachePath/realisation892=== CONT TestService_NativeMTLS893=== PAUSE TestIsValidCachePath/realisation894=== RUN TestIsValidCachePath/nix-cache-info895=== PAUSE TestIsValidCachePath/nix-cache-info896=== RUN TestIsValidCachePath/index.html897=== PAUSE TestIsValidCachePath/index.html898=== RUN TestIsValidCachePath/traversal_parent899=== PAUSE TestIsValidCachePath/traversal_parent900=== RUN TestIsValidCachePath/traversal_in_middle901=== PAUSE TestIsValidCachePath/traversal_in_middle902=== RUN TestIsValidCachePath/invalid_char_e903=== PAUSE TestIsValidCachePath/invalid_char_e904=== RUN TestIsValidCachePath/invalid_char_u905=== PAUSE TestIsValidCachePath/invalid_char_u906=== RUN TestIsValidCachePath/random_path907=== PAUSE TestIsValidCachePath/random_path908=== RUN TestIsValidCachePath/empty909=== PAUSE TestIsValidCachePath/empty910=== RUN TestIsValidCachePath/leading_slash911=== PAUSE TestIsValidCachePath/leading_slash912=== RUN TestIsValidCachePath/wrong_extension913=== PAUSE TestIsValidCachePath/wrong_extension914=== RUN TestIsValidCachePath/short_hash915=== PAUSE TestIsValidCachePath/short_hash916=== CONT TestCreatePendingClosureRejectsOversizedNAR9172026/10/27 08:51:09 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.03s)919=== CONT TestNARDeduplicationMetadataUploadBug9202026/10/27 08:51:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42399/oidc9212026/10/27 08:51:10 INFO Received push request method=POST path=/api/pushes9222026/10/27 08:51:10 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"9232026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9242026/10/27 08:51:10 INFO Signed narinfos id=1 count=19252026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9262026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9272026/10/27 08:51:10 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9282026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9292026/10/27 08:51:10 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9302026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9312026/10/27 08:51:10 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19322026/10/27 08:51:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign933--- PASS: TestService_AuthMiddleware (1.76s)934=== CONT TestChildrenInheritRaisedFileLimit9352026/10/27 08:51:10 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo936--- PASS: TestChildrenInheritRaisedFileLimit (0.01s)937=== CONT TestGenerateLandingPage938--- PASS: TestGenerateLandingPage (0.04s)939=== CONT TestCacheConfigHandlerMaxNarSize940--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)941=== CONT TestService_readinessHandler942--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.83s)943=== CONT TestGracefulShutdownDrainsInflight9442026/10/27 08:51:10 INFO Starting HTTP server address=127.0.0.1:445699452026/10/27 08:51:10 INFO Shutdown signal received, draining in-flight requests timeout=10s946=== CONT TestService_healthCheckHandler947--- PASS: TestGracefulShutdownDrainsInflight (0.08s)948=== CONT TestGCTaskStore_PhaseUpdates949--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)950=== CONT TestGCTaskStore_Fail951--- PASS: TestGCTaskStore_Fail (0.00s)952=== CONT TestGCTaskStore_CompletedAllowsNewTask953--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)954=== CONT TestGCTaskStore_GetEmpty955--- PASS: TestGCTaskStore_GetEmpty (0.00s)956=== CONT TestGCTaskStore_GetReturnsLatest957--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)958=== CONT TestGCTaskStore_ConflictDifferentParams959--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)960=== CONT TestGCTaskStore_StartNew961--- PASS: TestGCTaskStore_StartNew (0.00s)962=== CONT TestGCTaskStore_DeduplicateSameParams963--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)964=== CONT TestCommitRacingPendingCleanupKeepsObjects965--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.93s)9662026/10/27 08:51:11 INFO Aborted multipart uploads count=0 kept=09672026/10/27 08:51:11 WARN Force mode enabled - objects will be deleted immediately without grace period9682026/10/27 08:51:11 INFO Received uploads request method=POST path=/api/pending_closures9692026/10/27 08:51:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09702026/10/27 08:51:11 INFO Vacuumed table table=pending_closures9712026/10/27 08:51:11 INFO Vacuumed table table=pending_objects9722026/10/27 08:51:11 INFO Vacuumed table table=multipart_uploads9732026/10/27 08:51:11 INFO Vacuumed table table=closures9742026/10/27 08:51:11 INFO Vacuumed table table=objects9752026/10/27 08:51:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9762026/10/27 08:51:11 INFO Received uploads request method=POST path=/api/pending_closures977=== CONT TestGCEndsOnShutdown978=== RUN TestGCEndsOnShutdown/before_the_run979=== PAUSE TestGCEndsOnShutdown/before_the_run980=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete981=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete982=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark983=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark984=== CONT TestPushWaitsForSweepHoldingRow985--- PASS: TestSweepRechecksPendingAfterLocking (2.22s)986--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.26s)987=== CONT TestGetExistingObjectsLocksRows988--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.35s)989=== CONT TestRegisterCompletedObjectNeedsPendingRow9902026/10/27 08:51:11 INFO Received push request method=POST path=/api/pushes991--- PASS: TestReadProxyRangeRequest (2.63s)992=== CONT TestSweepSkipsRowsLockedByPush9932026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9942026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9952026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9962026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9972026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9982026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy9992026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy10002026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy10012026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/deploy10022026/10/27 08:51:11 INFO Received create pin request method=POST path=/api/pins/app10032026/10/27 08:51:11 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10042026/10/27 08:51:11 INFO Received delete pin request method=DELETE path=/api/pins/app10052026/10/27 08:51:11 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10062026/10/27 08:51:11 INFO Received delete pin request method=DELETE path=/api/pins/app10072026/10/27 08:51:11 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/27 08:51:12 INFO Deleted pin name=app1009--- PASS: TestDeletePinKeepsRowWhenS3Fails (3.09s)1010=== CONT TestFailedS3DeleteKeepsTombstone10112026/10/27 08:51:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10122026/10/27 08:51:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10132026/10/27 08:51:12 INFO Aborted multipart uploads count=0 kept=110142026/10/27 08:51:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10152026/10/27 08:51:12 INFO Aborted multipart uploads count=1 kept=01016--- PASS: TestMultipartCleanup (3.26s)1017=== CONT TestForceGCDuringPushOffersSweptObject1018=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1019=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1020=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1021=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1022=== CONT TestGCSweepDeliversEachKeyOnce1023=== CONT TestTombstonedObjectOfferedWithoutWaiting1024--- PASS: TestReadProxyNarStreaming (3.26s)1025=== CONT TestGCSweepSkipsPendingObjects1026--- PASS: TestPresentReportsOnlyClosureRoots (3.49s)10272026/10/27 08:51:12 INFO Received push request method=POST path=/api/pushes10282026/10/27 08:51:12 INFO Received create pin request method=POST path=/api/pins/deploy10292026/10/27 08:51:12 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1030--- PASS: TestCreatePinRejectsBadInput (3.66s)1031=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10322026/10/27 08:51:12 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/27 08:51:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10342026/10/27 08:51:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10352026/10/27 08:51:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1036--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.78s)1037=== CONT TestPushDedupSurvivesConcurrentGC1038--- PASS: TestService_NativeMTLS (3.54s)1039=== CONT TestGCMetrics10402026/10/27 08:51:13 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjg1YzEyZDE1LWM2MWEtNDk0Yy1iYjRhLTRmNzNmOTYzODE0YngxNzkzMDkxMDcxNDI2MzQ4Mjcy parts=1010412026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10422026/10/27 08:51:13 WARN Refused reserved pin name=worker-x86_64-linux10432026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10442026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/my-app10452026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1046--- PASS: TestCreatePin_ReservedPins (4.16s)1047=== CONT TestGCBugBareHashReferences10482026/10/27 08:51:13 INFO Received uploads request method=POST path=/api/pending_closures1049--- PASS: TestMetricsInventory (4.55s)1050=== CONT TestDeduplicatedObjectsRecordedAsPending10512026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/app10522026/10/27 08:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10532026/10/27 08:51:13 INFO Received create pin request method=POST path=/api/pins/app10542026/10/27 08:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/10/27 08:51:13 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA51056=== CONT TestLeadEndsOnShutdown1057--- PASS: TestReadRedirectKeepsNarinfoProxied (4.96s)10582026/10/27 08:51:13 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA5 error="Delete \"http://localhost:35977/bucket22/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA5\": injected: abort refused"10592026/10/27 08:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10602026/10/27 08:51:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA510612026/10/27 08:51:14 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>10622026/10/27 08:51:14 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst10632026/10/27 08:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/10/27 08:51:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA51065--- PASS: TestReadProxyNarinfo (5.06s)1066=== CONT TestLeadIncumbentAnnouncesAtOnce10672026/10/27 08:51:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyYTg0MDM5LTZiZDItNDUxYi04ZGY4LTc0NjE5ZWQ3MDVlY3gxNzkzMDkxMDczMjkxODAxNjA5 parts=110682026/10/27 08:51:14 WARN readiness check failed error="closed pool"1069--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.15s)1070=== CONT TestLeadElectsOneAndHandsOver1071--- PASS: TestService_readinessHandler (3.38s)1072=== CONT TestConnectSerialisesConcurrentMigrations10732026/10/27 08:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10742026/10/27 08:51:14 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10752026/10/27 08:51:14 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjlhMGQyYzJhLTMxNjEtNDU1OC1hYWUyLTRlOGM1ODQ1ZDBjMXgxNzkzMDkxMDcxNDE3NDIwMjE0 parts=1010762026/10/27 08:51:14 INFO Received complete push request method=POST path=/api/pushes/1/complete10772026/10/27 08:51:14 INFO Completed push id=1 objects=4 duration=29.058254ms1078--- PASS: TestService_healthCheckHandler (3.43s)1079=== CONT TestConnectWaitsForAPeerMigration10802026/10/27 08:51:14 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1081=== CONT TestGCAdvisoryLockBlocksConcurrentRun1082--- PASS: TestPush_RepeatedRootCommitsOnce (5.39s)1083--- PASS: TestConcurrentPinUpdatesAgree (5.44s)1084=== CONT TestResolveDBConnectionString1085=== RUN TestResolveDBConnectionString/flag_wins1086=== PAUSE TestResolveDBConnectionString/flag_wins1087=== RUN TestResolveDBConnectionString/file_when_flag_empty1088=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1089=== RUN TestResolveDBConnectionString/missing_file_is_an_error1090=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1091=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1092=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1093=== RUN TestResolveDBConnectionString/nothing_configured1094=== PAUSE TestResolveDBConnectionString/nothing_configured1095=== CONT TestDeleteClosuresRacingPins1096--- PASS: TestReadProxyContentNegotiation (5.58s)1097=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10982026/10/27 08:51:15 INFO Received uploads request method=POST path=/api/pending_closures10992026/10/27 08:51:15 INFO Aborted multipart uploads count=0 kept=011002026/10/27 08:51:15 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmE3OGY1NDdiLTE3YzYtNDBjNi1hYjA4LWQzMzJhMGRmMWU5YXgxNzkzMDkxMDcyNTg1NTgzODMy parts=101101--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.84s)1102=== CONT TestClientPushesUseOnePush11032026-10-27 08:51:15.258 UTC [642] ERROR: relation "goose_db_version" already exists11042026-10-27 08:51:15.258 UTC [642] STATEMENT: CREATE TABLE goose_db_version (1105 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1106 version_id bigint NOT NULL,1107 is_applied boolean NOT NULL,1108 tstamp timestamp NOT NULL DEFAULT now()1109 )11102026/10/27 08:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period11112026/10/27 08:51:15 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=011122026/10/27 08:51:15 INFO Vacuumed table table=pending_closures11132026/10/27 08:51:15 INFO Vacuumed table table=pending_objects11142026/10/27 08:51:15 INFO Vacuumed table table=multipart_uploads11152026/10/27 08:51:15 INFO Vacuumed table table=closures11162026/10/27 08:51:15 INFO Vacuumed table table=objects1117=== NAME TestNARDeduplicationMetadataUploadBug1118 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2910499385/001/store/rp7z0d5np668j92yacw9j6ybjq1yjf6j-file1.txt1119--- PASS: TestGetExistingObjectsLocksRows (4.13s)1120=== CONT TestPinProtectsFromGC1121--- PASS: TestCommitRacingPendingCleanupKeepsObjects (4.52s)1122=== CONT TestClientFallsBackToClosures11232026/10/27 08:51:15 INFO Aborted multipart uploads count=0 kept=011242026/10/27 08:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/27 08:51:15 INFO Received uploads request method=POST path=/api/pending_closures11262026/10/27 08:51:15 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/27 08:51:15 INFO Vacuumed table table=pending_closures11282026/10/27 08:51:15 INFO Vacuumed table table=pending_objects11292026/10/27 08:51:15 INFO Vacuumed table table=multipart_uploads11302026/10/27 08:51:15 INFO Vacuumed table table=closures11312026/10/27 08:51:15 INFO Vacuumed table table=objects11322026/10/27 08:51:15 INFO Aborted multipart uploads count=0 kept=01133--- PASS: TestPushWaitsForSweepHoldingRow (4.47s)1134=== CONT TestClientSharedPathCommittedMidPush11352026/10/27 08:51:15 INFO Aborted multipart uploads count=0 kept=011362026/10/27 08:51:16 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/27 08:51:16 INFO Aborted multipart uploads count=0 kept=011382026/10/27 08:51:16 WARN Force mode enabled - objects will be deleted immediately without grace period1139--- PASS: TestTombstonedObjectOfferedWithoutWaiting (3.77s)1140=== CONT TestReadProxyConditionalGet11412026/10/27 08:51:16 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/27 08:51:16 INFO Received push request method=POST path=/api/pushes11432026/10/27 08:51:16 WARN Force mode enabled - objects will be deleted immediately without grace period11442026/10/27 08:51:16 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=011452026/10/27 08:51:16 INFO Vacuumed table table=pending_closures11462026/10/27 08:51:16 INFO Vacuumed table table=pending_objects11472026/10/27 08:51:16 INFO Vacuumed table table=multipart_uploads11482026/10/27 08:51:16 INFO Vacuumed table table=closures11492026/10/27 08:51:16 INFO Vacuumed table table=objects11502026/10/27 08:51:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11512026/10/27 08:51:16 INFO Uploading rp7z0d5np668j92yacw9j6ybjq1yjf6j-file1.txt (160B)1152--- PASS: TestGCSweepDeliversEachKeyOnce (4.07s)1153=== CONT TestClientWithDependencies1154=== CONT TestReadProxyOutlastsServerWriteTimeout1155--- PASS: TestConnectSerialisesConcurrentMigrations (2.14s)11562026/10/27 08:51:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11572026/10/27 08:51:16 WARN Failed to register uploaded object key=rp7z0d5np668j92yacw9j6ybjq1yjf6j.ls error="server returned 404: 404 page not found\n"11582026/10/27 08:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11592026/10/27 08:51:16 INFO lead: acquired remote=192.0.2.1:123411602026/10/27 08:51:16 INFO Signed narinfos id=1 count=111612026/10/27 08:51:16 INFO Uploading 1 narinfos11622026/10/27 08:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11632026/10/27 08:51:16 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=011642026/10/27 08:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete11652026/10/27 08:51:16 INFO Vacuumed table table=pending_closures11662026/10/27 08:51:16 INFO Vacuumed table table=pending_objects11672026/10/27 08:51:16 INFO Vacuumed table table=multipart_uploads11682026/10/27 08:51:16 INFO Vacuumed table table=closures11692026/10/27 08:51:16 WARN Failed to register uploaded object key=rp7z0d5np668j92yacw9j6ybjq1yjf6j.narinfo error="server returned 404: 404 page not found\n"11702026/10/27 08:51:16 INFO Completed push id=1 objects=3 duration=13.217936ms11712026/10/27 08:51:16 INFO Upload complete. (849ms)11722026/10/27 08:51:16 INFO Vacuumed table table=objects1173=== NAME TestNARDeduplicationMetadataUploadBug1174 metadata_upload_test.go:54: Retrieved narinfo from S3:1175 StorePath: /build/TestNARDeduplicationMetadataUploadBug2910499385/001/store/rp7z0d5np668j92yacw9j6ybjq1yjf6j-file1.txt1176 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1177 Compression: zstd1178 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1179 NarSize: 1601180 References: 1181 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1182 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1183 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1184 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11852026/10/27 08:51:16 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjNhZDVlMGI2LTEyNzItNDUyMS1iZmMxLWNmNGRlZDljMjA1MHgxNzkzMDkxMDcyNTg0NzEyOTQ1 parts=1011862026/10/27 08:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete1187--- PASS: TestSweepSkipsRowsLockedByPush (4.79s)1188=== CONT TestClientMultipleUploads11892026/10/27 08:51:16 INFO Completed push id=1 objects=4 duration=8.338973ms11902026/10/27 08:51:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1191--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (3.77s)1192=== CONT TestReadProxyHead1193=== NAME TestNARDeduplicationMetadataUploadBug11942026/10/27 08:51:16 INFO Completed upload id=2 objects=2 duration=7.309944ms1195 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2910499385/001/store/qz8p6b7y6sfvpz3cmj8y5qw9aky5s5sb-file2.txt11962026/10/27 08:51:16 INFO Aborted multipart uploads count=0 kept=011972026/10/27 08:51:16 WARN Force mode enabled - objects will be deleted immediately without grace period11982026/10/27 08:51:16 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=011992026/10/27 08:51:16 INFO Vacuumed table table=pending_closures12002026/10/27 08:51:16 INFO Vacuumed table table=pending_objects12012026/10/27 08:51:16 INFO Vacuumed table table=multipart_uploads12022026/10/27 08:51:16 INFO Vacuumed table table=closures12032026/10/27 08:51:16 INFO Vacuumed table table=objects1204--- PASS: TestMetricsCommit (7.23s)1205=== CONT TestClientErrorHandling1206=== RUN TestClientErrorHandling/InvalidStorePath1207=== PAUSE TestClientErrorHandling/InvalidStorePath1208=== RUN TestClientErrorHandling/InvalidAuthToken1209=== PAUSE TestClientErrorHandling/InvalidAuthToken1210=== RUN TestClientErrorHandling/ServerNotAvailable1211=== PAUSE TestClientErrorHandling/ServerNotAvailable1212=== CONT TestReadProxyDisabled1213--- PASS: TestGCMetrics (3.76s)1214=== CONT TestClientCADerivations12152026/10/27 08:51:16 WARN Force mode enabled - objects will be deleted immediately without grace period12162026/10/27 08:51:16 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12172026/10/27 08:51:16 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12182026/10/27 08:51:16 INFO Received push request method=POST path=/api/pushes12192026/10/27 08:51:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12202026/10/27 08:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12212026/10/27 08:51:16 WARN Failed to register uploaded object key=qz8p6b7y6sfvpz3cmj8y5qw9aky5s5sb.ls error="server returned 404: 404 page not found\n"12222026/10/27 08:51:16 INFO Signed narinfos id=2 count=11223--- PASS: TestFailedS3DeleteKeepsTombstone (4.81s)1224=== CONT TestReadProxy404And42912252026/10/27 08:51:16 INFO Uploading 1 narinfos12262026/10/27 08:51:17 INFO Received complete push request method=POST path=/api/pushes/2/complete12272026/10/27 08:51:17 WARN Failed to register uploaded object key=qz8p6b7y6sfvpz3cmj8y5qw9aky5s5sb.narinfo error="server returned 404: 404 page not found\n"12282026/10/27 08:51:17 INFO Completed push id=2 objects=3 duration=17.189611ms12292026/10/27 08:51:17 INFO Upload complete. (445ms)12302026/10/27 08:51:17 INFO Received uploads request method=POST path=/api/pending_closures1231=== NAME TestNARDeduplicationMetadataUploadBug1232 metadata_upload_test.go:76: Retrieved narinfo from S3:1233 StorePath: /build/TestNARDeduplicationMetadataUploadBug2910499385/001/store/qz8p6b7y6sfvpz3cmj8y5qw9aky5s5sb-file2.txt1234 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1235 Compression: zstd1236 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1237 NarSize: 1601238 References: 1239 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1240 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1241 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1242 {"version":1,"root":{"type":"regular","size":44}}1243--- PASS: TestNARDeduplicationMetadataUploadBug (7.88s)1244=== CONT TestCacheStatsHandler1245--- PASS: TestDeduplicatedObjectsRecordedAsPending (3.74s)1246=== CONT TestReadProxyInvalidPath12472026/10/27 08:51:17 INFO lead: acquired remote=192.0.2.1:123412482026/10/27 08:51:17 INFO lead: released remote=192.0.2.1:123412492026/10/27 08:51:17 INFO lead: released remote=192.0.2.1:12341250--- PASS: TestLeadIncumbentAnnouncesAtOnce (3.51s)1251=== CONT TestClientIntegration12522026/10/27 08:51:17 INFO lead: acquired remote=192.0.2.1:12341253--- PASS: TestGCBugBareHashReferences (5.03s)1254=== CONT TestCacheConfigHandler1255=== RUN TestCacheConfigHandler/full_config,_no_issuer1256=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1257=== RUN TestCacheConfigHandler/no_cache_url_configured1258=== PAUSE TestCacheConfigHandler/no_cache_url_configured1259=== RUN TestCacheConfigHandler/no_signing_keys1260=== PAUSE TestCacheConfigHandler/no_signing_keys1261=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1262=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1263=== CONT TestService_ReadScope_PublicByDefault12642026/10/27 08:51:18 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/27 08:51:18 INFO lead: acquired remote=192.0.2.1:123412662026/10/27 08:51:18 INFO Aborted multipart uploads count=0 kept=012672026/10/27 08:51:18 INFO Received uploads request method=POST path=/api/pending_closures1268--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.07s)1269=== CONT TestService_AuthMiddleware_OIDC12702026/10/27 08:51:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35441/oidc12712026/10/27 08:51:18 INFO lead: released remote=192.0.2.1:123412722026/10/27 08:51:18 INFO Aborted multipart uploads count=0 kept=01273--- PASS: TestLeadElectsOneAndHandsOver (4.66s)1274=== CONT TestService_RequireScope_OIDC12752026/10/27 08:51: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=012762026/10/27 08:51:18 WARN Force mode enabled - objects will be deleted immediately without grace period12772026/10/27 08:51:18 INFO Vacuumed table table=pending_closures12782026/10/27 08:51: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=012792026/10/27 08:51:18 INFO Vacuumed table table=pending_objects12802026/10/27 08:51:18 INFO Vacuumed table table=multipart_uploads12812026/10/27 08:51:18 INFO Vacuumed table table=closures12822026/10/27 08:51:18 INFO Vacuumed table table=pending_closures12832026/10/27 08:51:18 INFO Vacuumed table table=pending_objects12842026/10/27 08:51:18 INFO Vacuumed table table=multipart_uploads12852026/10/27 08:51:18 INFO Vacuumed table table=closures12862026/10/27 08:51:18 INFO Vacuumed table table=objects12872026/10/27 08:51:18 INFO Vacuumed table table=objects12882026/10/27 08:51:18 INFO Aborted multipart uploads count=0 kept=012892026/10/27 08:51:18 WARN Force mode enabled - objects will be deleted immediately without grace period12902026/10/27 08:51: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=012912026/10/27 08:51:18 INFO Vacuumed table table=pending_closures12922026/10/27 08:51:18 INFO Vacuumed table table=pending_objects12932026/10/27 08:51:19 INFO Vacuumed table table=multipart_uploads12942026/10/27 08:51:19 INFO Vacuumed table table=closures12952026/10/27 08:51:19 INFO Vacuumed table table=objects12962026/10/27 08:51:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43021/oidc1297--- PASS: TestGCSweepSkipsPendingObjects (6.55s)1298=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1299--- PASS: TestPushDedupSurvivesConcurrentGC (6.29s)1300=== CONT TestService_AuthMiddleware_MTLSProxyHeader1301--- PASS: TestReadProxyConditionalGet (3.07s)1302=== CONT TestService_ReadAuthMiddleware13032026/10/27 08:51:19 INFO Received push request method=POST path=/api/pushes13042026/10/27 08:51:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13052026/10/27 08:51:19 INFO Uploading pz39s0m1g66g2zxd81ih68a300gc56ka-a (216B)13062026/10/27 08:51:19 INFO Uploading lwx8cji640wdz9sxgsgagh9xv4g1x44i-shared-dep (136B)13072026/10/27 08:51:19 WARN Failed to register uploaded object key=nar/1idc9q44ghqnr2gkp7n9v251in09405dc3yz8fawq33f8vksvlab.nar.zst error="server returned 404: 404 page not found\n"13082026/10/27 08:51:19 WARN Failed to register uploaded object key=pz39s0m1g66g2zxd81ih68a300gc56ka.ls error="server returned 404: 404 page not found\n"13092026/10/27 08:51:19 INFO lead: released remote=192.0.2.1:123413102026/10/27 08:51:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13112026/10/27 08:51:19 WARN Failed to register uploaded object key=0vw3iryzdp2n59iv85nvhbnr78xidvqw.ls error="server returned 404: 404 page not found\n"13122026/10/27 08:51:19 WARN Failed to register uploaded object key=lwx8cji640wdz9sxgsgagh9xv4g1x44i.ls error="server returned 404: 404 page not found\n"13132026/10/27 08:51:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13142026/10/27 08:51:19 INFO Signed narinfos id=1 count=313152026/10/27 08:51:19 INFO Uploading 3 narinfos1316--- PASS: TestLeadEndsOnShutdown (5.45s)1317=== CONT TestPresentNotReportedWhileGCDeletesClosure1318=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1319=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1320=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1321=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1322=== CONT TestParseSingleRange1323=== RUN TestParseSingleRange/none1324=== PAUSE TestParseSingleRange/none1325=== RUN TestParseSingleRange/unknown_unit1326=== PAUSE TestParseSingleRange/unknown_unit1327=== RUN TestParseSingleRange/multi-range_ignored1328=== PAUSE TestParseSingleRange/multi-range_ignored1329=== RUN TestParseSingleRange/malformed_no_dash1330=== PAUSE TestParseSingleRange/malformed_no_dash1331=== RUN TestParseSingleRange/malformed_both_empty1332=== PAUSE TestParseSingleRange/malformed_both_empty1333=== RUN TestParseSingleRange/malformed_end_before_start1334=== PAUSE TestParseSingleRange/malformed_end_before_start1335=== RUN TestParseSingleRange/closed1336=== PAUSE TestParseSingleRange/closed1337=== RUN TestParseSingleRange/open-ended1338=== PAUSE TestParseSingleRange/open-ended1339=== RUN TestParseSingleRange/end_clamped_to_size1340=== PAUSE TestParseSingleRange/end_clamped_to_size1341=== RUN TestParseSingleRange/suffix1342=== PAUSE TestParseSingleRange/suffix1343=== RUN TestParseSingleRange/suffix_exceeds_size1344=== PAUSE TestParseSingleRange/suffix_exceeds_size1345=== RUN TestParseSingleRange/single_byte1346=== PAUSE TestParseSingleRange/single_byte1347=== RUN TestParseSingleRange/start_past_EOF1348=== PAUSE TestParseSingleRange/start_past_EOF1349=== RUN TestParseSingleRange/start_far_past_EOF1350=== PAUSE TestParseSingleRange/start_far_past_EOF1351=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13522026/10/27 08:51:19 WARN Failed to register uploaded object key=lwx8cji640wdz9sxgsgagh9xv4g1x44i.narinfo error="server returned 404: 404 page not found\n"13532026/10/27 08:51:19 WARN Failed to register uploaded object key=pz39s0m1g66g2zxd81ih68a300gc56ka.narinfo error="server returned 404: 404 page not found\n"13542026/10/27 08:51:19 INFO Received complete push request method=POST path=/api/pushes/1/complete13552026/10/27 08:51:19 WARN Failed to register uploaded object key=0vw3iryzdp2n59iv85nvhbnr78xidvqw.narinfo error="server returned 404: 404 page not found\n"13562026/10/27 08:51:19 INFO Completed push id=1 objects=8 duration=33.10203ms13572026/10/27 08:51:19 INFO Upload complete. (861ms)1358=== NAME TestClientPushesUseOnePush1359 client_pushes_test.go:97: Retrieved narinfo from S3:1360 StorePath: /build/TestClientPushesUseOnePush1423224401/001/store/lwx8cji640wdz9sxgsgagh9xv4g1x44i-shared-dep1361 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1362 Compression: zstd1363 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821364 NarSize: 1361365 References: 1366 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1367 client_pushes_test.go:97: Retrieved narinfo from S3:1368 StorePath: /build/TestClientPushesUseOnePush1423224401/001/store/pz39s0m1g66g2zxd81ih68a300gc56ka-a1369 URL: nar/1idc9q44ghqnr2gkp7n9v251in09405dc3yz8fawq33f8vksvlab.nar.zst1370 Compression: zstd1371 NarHash: sha256:1idc9q44ghqnr2gkp7n9v251in09405dc3yz8fawq33f8vksvlab1372 NarSize: 2161373 References: /build/TestClientPushesUseOnePush1423224401/001/store/lwx8cji640wdz9sxgsgagh9xv4g1x44i-shared-dep1374 CA: text:sha256:0rnm1hkhcpm24k59l8qhq9hpfarv8i8ad9c6z77q2s39az9gq8l61375 client_pushes_test.go:97: Retrieved narinfo from S3:1376 StorePath: /build/TestClientPushesUseOnePush1423224401/001/store/0vw3iryzdp2n59iv85nvhbnr78xidvqw-b1377 URL: nar/1idc9q44ghqnr2gkp7n9v251in09405dc3yz8fawq33f8vksvlab.nar.zst1378 Compression: zstd1379 NarHash: sha256:1idc9q44ghqnr2gkp7n9v251in09405dc3yz8fawq33f8vksvlab1380 NarSize: 2161381 References: /build/TestClientPushesUseOnePush1423224401/001/store/lwx8cji640wdz9sxgsgagh9xv4g1x44i-shared-dep1382 CA: text:sha256:0rnm1hkhcpm24k59l8qhq9hpfarv8i8ad9c6z77q2s39az9gq8l61383--- PASS: TestClientPushesUseOnePush (4.52s)1384=== CONT TestPush_CompleteWaitsForCleanupOfThePush1385=== NAME TestClientMultipleUploads1386 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads3983537396/001/store/9rlqjh45q39mclgk4k5hzjc06vp9x0j4-test-file-0.txt1387 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads3983537396/001/store/bc792na5cgc489qn1dzs0q1p1b5n9i7a-test-file-1.txt1388 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads3983537396/001/store/isxs332vsks9kpidm1lcrc3d5235aj8y-test-file-2.txt1389--- PASS: TestReadProxyHead (3.85s)1390=== CONT TestPush_CompleteCommitsEveryRoot1391--- PASS: TestReadProxyDisabled (3.93s)1392=== CONT TestPush_RootsAreLockedInByteOrder1393=== NAME TestClientWithDependencies1394 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies3544748792/001/store/2n6mdbzhas0qkqzqlkvnvkkd0i8r80m5-test-script1395--- PASS: TestCacheStatsHandler (3.66s)1396=== CONT TestPush_RejectsBadRequests1397--- PASS: TestReadProxyInvalidPath (3.81s)1398=== CONT TestUploadHandlersRejectInvalidKeys1399=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1400=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1401=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1402=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1403=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1404=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1405=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1406=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1407=== CONT TestService_verifyS3Integrity14082026/10/27 08:51:21 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"14092026/10/27 08:51:21 WARN Rate limiter enabled after throttle name=s3-test rate=514102026/10/27 08:51:21 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1411--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.22s)1412=== CONT TestService_createPendingClosureHandler14132026/10/27 08:51:21 WARN Rate limiter backed off name=s3-test rate=514142026/10/27 08:51:21 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1415--- PASS: TestReadProxy404And429 (4.80s)1416=== CONT TestCompleteMultipartUnregistered1417--- PASS: TestService_ReadScope_PublicByDefault (3.61s)1418=== CONT TestService_cleanupPendingClosuresHandler1419=== NAME TestClientIntegration1420 client_integration_test.go:331: Created store path: /build/TestClientIntegration356371126/002/store/kpcv8jfqfg3lk43a8g75pifvqrbplnxa-test-file.txt1421=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1422=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1423=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1424=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1425=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1426=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1427=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1428=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1429=== CONT TestUploadHandlersRejectOversizedBody1430--- PASS: TestService_ReadAuthMiddleware (3.15s)1431=== CONT TestIsValidUploadKey1432=== RUN TestIsValidUploadKey/narinfo1433=== PAUSE TestIsValidUploadKey/narinfo1434=== RUN TestIsValidUploadKey/nar_zst1435=== PAUSE TestIsValidUploadKey/nar_zst1436=== RUN TestIsValidUploadKey/nar_xz1437=== PAUSE TestIsValidUploadKey/nar_xz1438=== RUN TestIsValidUploadKey/nar_plain1439=== PAUSE TestIsValidUploadKey/nar_plain1440=== RUN TestIsValidUploadKey/listing1441=== PAUSE TestIsValidUploadKey/listing1442=== RUN TestIsValidUploadKey/build_log1443=== PAUSE TestIsValidUploadKey/build_log1444=== RUN TestIsValidUploadKey/build_log_home-manager_file1445=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1446=== RUN TestIsValidUploadKey/build_log_plus_in_name1447=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1448=== RUN TestIsValidUploadKey/build_log_question_mark1449=== PAUSE TestIsValidUploadKey/build_log_question_mark1450=== RUN TestIsValidUploadKey/build_log_equals1451=== PAUSE TestIsValidUploadKey/build_log_equals1452=== RUN TestIsValidUploadKey/realisation1453=== PAUSE TestIsValidUploadKey/realisation1454=== RUN TestIsValidUploadKey/realisation_plus_in_output1455=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1456=== RUN TestIsValidUploadKey/nix-cache-info1457=== PAUSE TestIsValidUploadKey/nix-cache-info1458=== RUN TestIsValidUploadKey/index.html1459=== PAUSE TestIsValidUploadKey/index.html1460=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1461=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1462=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1463=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1464=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1465=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1466=== RUN TestIsValidUploadKey/traversal1467=== PAUSE TestIsValidUploadKey/traversal1468=== RUN TestIsValidUploadKey/traversal_nar1469=== PAUSE TestIsValidUploadKey/traversal_nar1470=== RUN TestIsValidUploadKey/absolute1471=== PAUSE TestIsValidUploadKey/absolute1472=== RUN TestIsValidUploadKey/empty_key1473=== PAUSE TestIsValidUploadKey/empty_key1474=== RUN TestIsValidUploadKey/unknown_type1475=== PAUSE TestIsValidUploadKey/unknown_type1476=== CONT TestPendingClosureFailureAbortsItsUploads1477=== RUN TestService_RequireScope_OIDC/builder_may_write1478=== PAUSE TestService_RequireScope_OIDC/builder_may_write1479=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1480=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1481=== RUN TestService_RequireScope_OIDC/ops_may_admin1482=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1483=== RUN TestService_RequireScope_OIDC/ops_may_not_write1484=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1485=== RUN TestService_RequireScope_OIDC/reader_may_not_write1486=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1487=== RUN TestService_RequireScope_OIDC/static_token_may_admin1488=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1489=== RUN TestService_RequireScope_OIDC/static_token_may_write1490=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1491=== RUN TestService_RequireScope_OIDC/reader_may_read1492=== PAUSE TestService_RequireScope_OIDC/reader_may_read1493=== RUN TestService_RequireScope_OIDC/writer_implies_read1494=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1495=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1496=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1497=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1498=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1499=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1500=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1501=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1502=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1503=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1504=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1505=== CONT TestOrphanedObjectsGC1506=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1507=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1508=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1509=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1510=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1511=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1512=== CONT TestReconnectLeavesObjectsUnlocked15132026/10/27 08:51:22 INFO Received push request method=POST path=/api/pushes15142026/10/27 08:51:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15152026/10/27 08:51:22 INFO Uploading bc792na5cgc489qn1dzs0q1p1b5n9i7a-test-file-1.txt (160B)15162026/10/27 08:51:22 INFO Uploading 9rlqjh45q39mclgk4k5hzjc06vp9x0j4-test-file-0.txt (160B)15172026/10/27 08:51:22 INFO Uploading isxs332vsks9kpidm1lcrc3d5235aj8y-test-file-2.txt (160B)1518=== NAME TestClientCADerivations1519 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3939792872/001/store/qzl050qahsdjzk52d0wfc29jn8q0rz76-ca-test15202026/10/27 08:51:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15212026/10/27 08:51:22 INFO Received push request method=POST path=/api/pushes15222026/10/27 08:51:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15232026/10/27 08:51:22 WARN Failed to register uploaded object key=isxs332vsks9kpidm1lcrc3d5235aj8y.ls error="server returned 404: 404 page not found\n"15242026/10/27 08:51:22 WARN Failed to register uploaded object key=bc792na5cgc489qn1dzs0q1p1b5n9i7a.ls error="server returned 404: 404 page not found\n"15252026/10/27 08:51:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15262026/10/27 08:51:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15272026/10/27 08:51:22 WARN Failed to register uploaded object key=9rlqjh45q39mclgk4k5hzjc06vp9x0j4.ls error="server returned 404: 404 page not found\n"15282026/10/27 08:51:22 INFO Signed narinfos id=1 count=315292026/10/27 08:51:22 INFO Uploading 3 narinfos15302026/10/27 08:51:22 WARN Failed to register uploaded object key=bc792na5cgc489qn1dzs0q1p1b5n9i7a.narinfo error="server returned 404: 404 page not found\n"15312026/10/27 08:51:22 WARN Failed to register uploaded object key=isxs332vsks9kpidm1lcrc3d5235aj8y.narinfo error="server returned 404: 404 page not found\n"15322026/10/27 08:51:22 INFO Received complete push request method=POST path=/api/pushes/1/complete15332026/10/27 08:51:22 WARN Failed to register uploaded object key=9rlqjh45q39mclgk4k5hzjc06vp9x0j4.narinfo error="server returned 404: 404 page not found\n"15342026/10/27 08:51:22 INFO Completed push id=1 objects=9 duration=21.796491ms15352026/10/27 08:51:22 INFO Upload complete. (1.939s)1536=== NAME TestClientMultipleUploads1537 client_integration_test.go:478: Uploaded 3 paths in 2.849430542s1538=== CONT TestOrphanedObjectsGCStressTest1539--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.48s)1540--- PASS: TestClientMultipleUploads (6.52s)1541=== CONT TestObjectStatsUpdatedOncePerCommit1542--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.90s)1543=== CONT TestObjectStatsTrigger15442026/10/27 08:51:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15452026/10/27 08:51:23 WARN mTLS auth: bound subjects configured but subject DN unavailable15462026/10/27 08:51:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1547--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.13s)1548=== CONT TestPresentRefreshesOnlyStaleClosures15492026/10/27 08:51:23 INFO Received push request method=POST path=/api/pushes1550=== NAME TestClientWithDependencies1551 client_integration_test.go:724: Found 1 dependencies (including self)1552=== NAME TestClientCADerivations1553 client_ca_test.go:139: Found 1 dependencies (including self)15542026/10/27 08:51:23 INFO Received push request method=POST path=/api/pushes1555--- PASS: TestDeleteClosuresRacingPins (9.25s)1556=== CONT TestReadRedirectUsesPublicS3URL15572026/10/27 08:51:23 INFO Received push request method=POST path=/api/pushes15582026/10/27 08:51:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/10/27 08:51:23 INFO Uploading 2n6mdbzhas0qkqzqlkvnvkkd0i8r80m5-test-script (136B)1560=== RUN TestPush_RejectsBadRequests/no_objects1561=== PAUSE TestPush_RejectsBadRequests/no_objects1562=== RUN TestPush_RejectsBadRequests/bad_root1563=== PAUSE TestPush_RejectsBadRequests/bad_root1564=== RUN TestPush_RejectsBadRequests/root_not_in_objects1565=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1566=== RUN TestPush_RejectsBadRequests/no_roots1567=== PAUSE TestPush_RejectsBadRequests/no_roots1568=== CONT TestRedundantMultipartUpload15692026/10/27 08:51:23 WARN Failed to register uploaded object key=log/dsyjma61wqizggqx4x7c8a9fh0z3f2cf-test-script.drv error="server returned 404: 404 page not found\n"15702026/10/27 08:51:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15712026/10/27 08:51:23 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15722026/10/27 08:51:23 WARN Failed to register uploaded object key=2n6mdbzhas0qkqzqlkvnvkkd0i8r80m5.ls error="server returned 404: 404 page not found\n"15732026/10/27 08:51:23 INFO Signed narinfos id=1 count=115742026/10/27 08:51:23 INFO Uploading 1 narinfos15752026/10/27 08:51:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15762026/10/27 08:51:23 WARN Failed to register uploaded object key=2n6mdbzhas0qkqzqlkvnvkkd0i8r80m5.narinfo error="server returned 404: 404 page not found\n"1577=== NAME TestPinProtectsFromGC1578 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC3913271367/001/store/7yagqwfhkb9snqirn2rypwqjrmn9s18z-pinned-file.txt1579 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC3913271367/001/store/98clw4f62sqd62kdhlphra7398haq9w1-unpinned-file.txt15802026/10/27 08:51:23 INFO Completed push id=1 objects=4 duration=66.902905ms15812026/10/27 08:51:23 INFO Upload complete. (344ms)15822026/10/27 08:51:23 INFO Aborted multipart uploads count=0 kept=015832026/10/27 08:51:23 INFO Received push request method=POST path=/api/pushes15842026/10/27 08:51:24 INFO Received push request method=POST path=/api/pushes15852026/10/27 08:51:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/10/27 08:51:24 INFO Uploading kpcv8jfqfg3lk43a8g75pifvqrbplnxa-test-file.txt (152B)15872026/10/27 08:51:24 WARN Failed to register uploaded object key=kpcv8jfqfg3lk43a8g75pifvqrbplnxa.ls error="server returned 404: 404 page not found\n"15882026/10/27 08:51:24 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15892026/10/27 08:51:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15902026/10/27 08:51:24 INFO Signed narinfos id=1 count=115912026/10/27 08:51:24 INFO Uploading 1 narinfos15922026/10/27 08:51:24 INFO Received complete push request method=POST path=/api/pushes/1/complete15932026/10/27 08:51:24 WARN Failed to register uploaded object key=kpcv8jfqfg3lk43a8g75pifvqrbplnxa.narinfo error="server returned 404: 404 page not found\n"15942026/10/27 08:51:24 INFO Received uploads request method=POST path=/api/pending_closures15952026/10/27 08:51:24 INFO Completed push id=1 objects=3 duration=16.03894ms15962026/10/27 08:51:24 INFO Upload complete. (793ms)15972026/10/27 08:51:24 INFO Received uploads request method=POST path=/api/pending_closures15982026/10/27 08:51:24 INFO Received uploads request method=POST path=/api/pending_closures15992026/10/27 08:51:24 INFO Received uploads request method=POST path=/api/pending_closures16002026/10/27 08:51:24 INFO Received push request method=POST path=/api/pushes16012026/10/27 08:51:24 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16022026/10/27 08:51:24 INFO Uploading 2pxvw8ybqrm5a5wjklmqh7q5x53p9nif-top (224B)16032026/10/27 08:51:24 INFO Uploading 1h3fggq1rj54d665vjr314x25wddawwg-shared-dep (136B)16042026/10/27 08:51:24 WARN Failed to register uploaded object key=nar/1x7cszrvppsy0al06h6drd8rx870j03nrciczdryzy1j1ymsb3m7.nar.zst error="server returned 404: 404 page not found\n"16052026/10/27 08:51:24 WARN Failed to register uploaded object key=2pxvw8ybqrm5a5wjklmqh7q5x53p9nif.ls error="server returned 404: 404 page not found\n"16062026/10/27 08:51:24 WARN Failed to register uploaded object key=1h3fggq1rj54d665vjr314x25wddawwg.ls error="server returned 404: 404 page not found\n"16072026/10/27 08:51:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16082026/10/27 08:51:24 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16092026/10/27 08:51:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16102026/10/27 08:51:24 INFO Signed narinfos id=1 count=216112026/10/27 08:51:24 INFO Uploading 2 narinfos16122026/10/27 08:51:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst16132026/10/27 08:51:24 WARN Failed to register uploaded object key=1h3fggq1rj54d665vjr314x25wddawwg.narinfo error="server returned 404: 404 page not found\n"16142026/10/27 08:51:24 WARN Failed to register uploaded object key=2pxvw8ybqrm5a5wjklmqh7q5x53p9nif.narinfo error="server returned 404: 404 page not found\n"16152026/10/27 08:51:24 INFO Received complete push request method=POST path=/api/pushes/1/complete16162026/10/27 08:51:24 INFO Completed push id=1 objects=6 duration=10.908996ms16172026/10/27 08:51:24 INFO Upload complete. (765ms)1618=== NAME TestClientSharedPathCommittedMidPush1619 client_integration_test.go:803: Retrieved narinfo from S3:1620 StorePath: /build/TestClientSharedPathCommittedMidPush108874628/001/store/1h3fggq1rj54d665vjr314x25wddawwg-shared-dep1621 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1622 Compression: zstd1623 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821624 NarSize: 1361625 References: 1626 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1627 client_integration_test.go:803: Retrieved narinfo from S3:1628 StorePath: /build/TestClientSharedPathCommittedMidPush108874628/001/store/2pxvw8ybqrm5a5wjklmqh7q5x53p9nif-top1629 URL: nar/1x7cszrvppsy0al06h6drd8rx870j03nrciczdryzy1j1ymsb3m7.nar.zst1630 Compression: zstd1631 NarHash: sha256:1x7cszrvppsy0al06h6drd8rx870j03nrciczdryzy1j1ymsb3m71632 NarSize: 2241633 References: /build/TestClientSharedPathCommittedMidPush108874628/001/store/1h3fggq1rj54d665vjr314x25wddawwg-shared-dep1634 CA: text:sha256:1bw4b8hb1d0gdwrzg4abhdnvinsdgcxm8wzpsb7az31ff4hjnnip1635=== CONT TestSkippedUploadsHandler1636--- PASS: TestCompleteMultipartUnregistered (3.01s)16372026/10/27 08:51:24 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001638--- PASS: TestClientSharedPathCommittedMidPush (9.10s)1639=== CONT TestProxyWriteTimeout1640=== RUN TestProxyWriteTimeout/narinfo1641=== PAUSE TestProxyWriteTimeout/narinfo1642=== RUN TestProxyWriteTimeout/1_GiB_nar1643=== PAUSE TestProxyWriteTimeout/1_GiB_nar1644=== RUN TestProxyWriteTimeout/10_GiB_nar1645=== PAUSE TestProxyWriteTimeout/10_GiB_nar1646=== RUN TestProxyWriteTimeout/unknown_size1647=== PAUSE TestProxyWriteTimeout/unknown_size1648=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1649--- PASS: TestSkippedUploadsHandler (0.07s)1650=== CONT TestParseSize1651--- PASS: TestParseSize (0.00s)1652=== CONT TestPendingClosureWriteTimeout1653=== RUN TestPendingClosureWriteTimeout/empty1654=== PAUSE TestPendingClosureWriteTimeout/empty1655=== RUN TestPendingClosureWriteTimeout/400_objects1656=== PAUSE TestPendingClosureWriteTimeout/400_objects1657=== RUN TestPendingClosureWriteTimeout/670k_objects1658=== PAUSE TestPendingClosureWriteTimeout/670k_objects1659=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1660=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1661=== CONT TestPendingClosureFailureTracksEveryUpload1662=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1663=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1664=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1665=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1666=== CONT TestPendingCleanupUsesOneCutoff16672026/10/27 08:51:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16682026/10/27 08:51:25 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjFhZTk4MTg5LWJjZTAtNGNhMy05ZWQ4LTdlY2ZkNmY2NWI1NXgxNzkzMDkxMDgzMzc3OTQyNTY4 parts=101669--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.95s)1670=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1671--- PASS: TestObjectStatsUpdatedOncePerCommit (2.33s)1672=== CONT TestCompletedNarNotReofferedAcrossClosures16732026/10/27 08:51:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16742026-10-27 08:51:25.454 UTC [1583] ERROR: Push does not exist: id=116752026-10-27 08:51:25.454 UTC [1583] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16762026-10-27 08:51:25.454 UTC [1583] STATEMENT: SELECT commit_push($1)1677--- PASS: TestObjectStatsTrigger (2.50s)1678=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16792026/10/27 08:51:25 WARN Force mode enabled - objects will be deleted immediately without grace period16802026/10/27 08:51:25 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=016812026/10/27 08:51:25 INFO Vacuumed table table=pending_closures16822026/10/27 08:51:25 INFO Vacuumed table table=pending_objects16832026/10/27 08:51:25 INFO Vacuumed table table=multipart_uploads16842026/10/27 08:51:25 INFO Vacuumed table table=closures1685--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (5.97s)1686=== CONT TestService_Rustfstest16872026/10/27 08:51:25 INFO Vacuumed table table=objects1688=== NAME TestClientWithDependencies1689 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3544748792/001/store) requires matching store prefix16902026/10/27 08:51:25 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYwYmFhZTYzLTg2MTYtNDUwNi1hNGFkLTQ3MjM2OGQyYjRlZHgxNzkzMDkxMDgzNTcwNjk0MTU0 parts=101691--- PASS: TestClientWithDependencies (9.46s)1692=== CONT TestReadRedirectNar16932026/10/27 08:51:25 INFO Received cleanup request method=DELETE path=/api/pending_closures16942026/10/27 08:51:25 INFO Aborted multipart uploads count=0 kept=016952026/10/27 08:51:25 INFO Received uploads request method=POST path=/api/pending_closures16962026/10/27 08:51:25 INFO Received push request method=POST path=/api/pushes16972026/10/27 08:51:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16982026/10/27 08:51:25 INFO Uploading 7yagqwfhkb9snqirn2rypwqjrmn9s18z-pinned-file.txt (128B)16992026/10/27 08:51:25 INFO Received uploads request method=POST path=/api/pending_closures17002026/10/27 08:51:25 INFO All 1 paths already cached1701=== NAME TestClientIntegration1702 client_integration_test.go:357: Retrieved narinfo from S3:1703 StorePath: /build/TestClientIntegration356371126/002/store/kpcv8jfqfg3lk43a8g75pifvqrbplnxa-test-file.txt1704 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1705 Compression: zstd1706 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11707 NarSize: 1521708 References: 1709 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11710 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1711 client_integration_test.go:358: Decompressed .ls content (64 bytes):1712 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}17132026/10/27 08:51:25 INFO Received uploads request method=POST path=/api/pending_closures17142026/10/27 08:51:25 INFO Received cleanup request method=DELETE path=/api/pending_closures17152026/10/27 08:51:25 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17162026/10/27 08:51:25 WARN Failed to register uploaded object key=7yagqwfhkb9snqirn2rypwqjrmn9s18z.ls error="server returned 404: 404 page not found\n"17172026/10/27 08:51:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17182026/10/27 08:51:25 INFO Signed narinfos id=1 count=117192026/10/27 08:51:26 INFO Uploading 1 narinfos17202026/10/27 08:51:26 INFO Aborted multipart uploads count=1 kept=017212026/10/27 08:51:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17222026/10/27 08:51:26 INFO Uploading qdyiyrls8n2i85rgl7smw3r9faysy3a7-b (216B)17232026/10/27 08:51:26 INFO Uploading dls09jla5cv481jrk23zlc398wilmq0s-shared-dep (136B)17242026/10/27 08:51:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17252026-10-27 08:51:26.075 UTC [1264] ERROR: Closure does not exist: id=117262026-10-27 08:51:26.075 UTC [1264] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE17272026-10-27 08:51:26.075 UTC [1264] STATEMENT: -- name: CommitPendingClosure :one1728 SELECT commit_pending_closure($1::bigint)::bigint1729 1730--- PASS: TestService_cleanupPendingClosuresHandler (4.33s)1731=== CONT TestServerTLSConfig1732=== RUN TestServerTLSConfig/no_client_CA1733=== PAUSE TestServerTLSConfig/no_client_CA1734=== RUN TestServerTLSConfig/missing_CA_file1735=== PAUSE TestServerTLSConfig/missing_CA_file1736=== RUN TestServerTLSConfig/not_a_PEM_file1737=== PAUSE TestServerTLSConfig/not_a_PEM_file1738=== CONT TestIsValidCachePath/nar_xz1739=== CONT TestIsValidCachePath/nix-cache-info1740=== CONT TestIsValidCachePath/short_hash1741=== CONT TestIsValidCachePath/leading_slash1742=== CONT TestIsValidCachePath/wrong_extension1743=== CONT TestIsValidCachePath/empty1744=== CONT TestIsValidCachePath/random_path1745=== CONT TestIsValidCachePath/invalid_char_e1746=== CONT TestIsValidCachePath/invalid_char_u1747=== CONT TestIsValidCachePath/traversal_in_middle1748=== CONT TestIsValidCachePath/index.html1749=== CONT TestIsValidCachePath/log1750=== CONT TestIsValidCachePath/traversal_parent1751=== CONT TestIsValidCachePath/realisation1752=== CONT TestIsValidCachePath/ls1753=== CONT TestIsValidCachePath/nar_uncompressed1754=== CONT TestIsValidCachePath/nar_zst1755=== CONT TestIsValidCachePath/nar_bz21756=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1757=== CONT TestIsValidCachePath/narinfo1758--- PASS: TestIsValidCachePath (0.36s)1759 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1760 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1761 --- PASS: TestIsValidCachePath/short_hash (0.00s)1762 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1763 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1764 --- PASS: TestIsValidCachePath/empty (0.00s)1765 --- PASS: TestIsValidCachePath/random_path (0.00s)1766 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1767 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1768 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1769 --- PASS: TestIsValidCachePath/index.html (0.00s)1770 --- PASS: TestIsValidCachePath/log (0.00s)1771 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1772 --- PASS: TestIsValidCachePath/realisation (0.00s)1773 --- PASS: TestIsValidCachePath/ls (0.00s)1774 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1775 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1776 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1777 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1778 --- PASS: TestIsValidCachePath/narinfo (0.00s)1779=== CONT TestGCEndsOnShutdown/before_the_run17802026/10/27 08:51:26 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/27 08:51:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17822026/10/27 08:51:26 WARN Failed to register uploaded object key=7yagqwfhkb9snqirn2rypwqjrmn9s18z.narinfo error="server returned 404: 404 page not found\n"17832026/10/27 08:51:26 WARN Failed to register uploaded object key=zfm9w8r47wrsx2blh1qvf9crp7sac07j.ls error="server returned 404: 404 page not found\n"17842026/10/27 08:51:26 WARN Failed to register uploaded object key=nar/07wh3rv7kjrmgi2bc3gx7nzl8jkph2cnq59ygfahjsp29cplz9vx.nar.zst error="server returned 404: 404 page not found\n"17852026/10/27 08:51:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17862026/10/27 08:51:26 INFO Completed push id=1 objects=3 duration=109.874601ms17872026/10/27 08:51:26 INFO Upload complete. (1.721s)17882026/10/27 08:51:26 WARN Failed to register uploaded object key=dls09jla5cv481jrk23zlc398wilmq0s.ls error="server returned 404: 404 page not found\n"17892026/10/27 08:51:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17902026/10/27 08:51:26 INFO Signed narinfos id=1 count=217912026/10/27 08:51:26 WARN Failed to register uploaded object key=qdyiyrls8n2i85rgl7smw3r9faysy3a7.ls error="server returned 404: 404 page not found\n"17922026/10/27 08:51:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17932026/10/27 08:51:26 INFO Signed narinfos id=2 count=217942026/10/27 08:51:26 INFO Uploading 4 narinfos17952026/10/27 08:51:26 WARN Failed to register uploaded object key=dls09jla5cv481jrk23zlc398wilmq0s.narinfo error="server returned 404: 404 page not found\n"17962026/10/27 08:51:26 WARN Failed to register uploaded object key=qdyiyrls8n2i85rgl7smw3r9faysy3a7.narinfo error="server returned 404: 404 page not found\n"17972026/10/27 08:51:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17982026/10/27 08:51:26 WARN Failed to register uploaded object key=zfm9w8r47wrsx2blh1qvf9crp7sac07j.narinfo error="server returned 404: 404 page not found\n"1799--- PASS: TestPendingClosureFailureAbortsItsUploads (4.37s)1800=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18012026/10/27 08:51:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18022026/10/27 08:51:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18032026/10/27 08:51:26 WARN Failed to register uploaded object key=dls09jla5cv481jrk23zlc398wilmq0s.narinfo error="server returned 404: 404 page not found\n"18042026/10/27 08:51:26 INFO Completed upload id=1 objects=6 duration=14.477487ms18052026/10/27 08:51:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18062026/10/27 08:51:26 INFO Completed upload id=2 objects=6 duration=3.959895ms18072026/10/27 08:51:26 INFO Upload complete. (3.318s)1808=== NAME TestClientFallsBackToClosures1809 client_pushes_test.go:112: Retrieved narinfo from S3:1810 StorePath: /build/TestClientFallsBackToClosures894734659/001/store/dls09jla5cv481jrk23zlc398wilmq0s-shared-dep1811 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1812 Compression: zstd1813 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821814 NarSize: 1361815 References: 1816 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1817 client_pushes_test.go:112: Retrieved narinfo from S3:1818 StorePath: /build/TestClientFallsBackToClosures894734659/001/store/zfm9w8r47wrsx2blh1qvf9crp7sac07j-a1819 URL: nar/07wh3rv7kjrmgi2bc3gx7nzl8jkph2cnq59ygfahjsp29cplz9vx.nar.zst1820 Compression: zstd1821 NarHash: sha256:07wh3rv7kjrmgi2bc3gx7nzl8jkph2cnq59ygfahjsp29cplz9vx1822 NarSize: 2161823 References: /build/TestClientFallsBackToClosures894734659/001/store/dls09jla5cv481jrk23zlc398wilmq0s-shared-dep1824 CA: text:sha256:19462hcs4cz1wg63j95hc1svxraj5v2pn2sa2m6ima1w5c29wy9d1825 client_pushes_test.go:112: Retrieved narinfo from S3:1826 StorePath: /build/TestClientFallsBackToClosures894734659/001/store/qdyiyrls8n2i85rgl7smw3r9faysy3a7-b1827 URL: nar/07wh3rv7kjrmgi2bc3gx7nzl8jkph2cnq59ygfahjsp29cplz9vx.nar.zst1828 Compression: zstd1829 NarHash: sha256:07wh3rv7kjrmgi2bc3gx7nzl8jkph2cnq59ygfahjsp29cplz9vx1830 NarSize: 2161831 References: /build/TestClientFallsBackToClosures894734659/001/store/dls09jla5cv481jrk23zlc398wilmq0s-shared-dep1832 CA: text:sha256:19462hcs4cz1wg63j95hc1svxraj5v2pn2sa2m6ima1w5c29wy9d1833--- PASS: TestClientFallsBackToClosures (11.50s)1834=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18352026/10/27 08:51:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjVlNDEyNmE3LTM3NTgtNDU4Yy1hNzQ4LTE2MjBhMWQxZWM3NHgxNzkzMDkxMDg0MTg0NTIzNTYz parts=1018362026/10/27 08:51:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18372026/10/27 08:51:26 INFO Completed upload id=1 objects=2 duration=25.636684ms1838--- PASS: TestPresentRefreshesOnlyStaleClosures (3.82s)1839=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18402026/10/27 08:51:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18412026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18422026/10/27 08:51:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjMwYTFhNTA4LTc1NmQtNGIzZC1iMzdjLTdhNGE3NzQ1Y2Q1ZngxNzkzMDkxMDg0Mzc5Mjg1NTg2 parts=1018432026/10/27 08:51:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18442026/10/27 08:51:27 INFO Completed upload id=1 objects=2 duration=11.613622ms18452026/10/27 08:51:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018462026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18482026/10/27 08:51:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures18492026/10/27 08:51:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18502026/10/27 08:51:27 WARN Found objects in DB but missing from S3, will re-upload count=118512026/10/27 08:51:27 INFO Aborted multipart uploads count=0 kept=018522026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures1853--- PASS: TestReconnectLeavesObjectsUnlocked (4.73s)1854=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18552026/10/27 08:51:27 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18562026/10/27 08:51:27 INFO Completed upload id=3 objects=2 duration=7.98249ms18572026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures1858--- PASS: TestService_verifyS3Integrity (6.17s)1859=== CONT TestResolveDBConnectionString/flag_wins1860=== CONT TestResolveDBConnectionString/missing_file_is_an_error1861=== CONT TestResolveDBConnectionString/nothing_configured1862=== CONT TestResolveDBConnectionString/file_when_flag_empty1863=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1864=== CONT TestClientErrorHandling/InvalidAuthToken1865--- PASS: TestResolveDBConnectionString (0.00s)1866 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1867 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1868 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1869 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1870 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)18712026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18722026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18732026/10/27 08:51:27 INFO Received cleanup request method=DELETE path=/api/pending_closures18742026/10/27 08:51:27 INFO Received uploads request method=POST path=/api/pending_closures18752026/10/27 08:51:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18762026/10/27 08:51:28 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmNjNWMwMmM1LTgzODktNDdlOC05NDhiLWVjYzI2NjNiY2I4M3gxNzkzMDkxMDgzNTcxNDg0MjYx parts=101877--- PASS: TestService_Rustfstest (2.47s)1878=== CONT TestClientErrorHandling/ServerNotAvailable1879=== CONT TestClientErrorHandling/InvalidStorePath18802026/10/27 08:51:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18812026/10/27 08:51:29 INFO Aborted multipart uploads count=0 kept=018822026/10/27 08:51:29 INFO Received uploads request method=POST path=/api/pending_closures1883--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (4.64s)1884=== CONT TestCacheConfigHandler/no_signing_keys1885=== CONT TestCacheConfigHandler/no_cache_url_configured1886=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1887=== CONT TestCacheConfigHandler/full_config,_no_issuer1888=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1889--- PASS: TestCacheConfigHandler (0.00s)1890 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1891 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1892 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1893 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)18942026/10/27 08:51:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18952026/10/27 08:51:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjM3NDBjNDYwLTliMDQtNGViMy1iODJmLThhNDAxOTMwNGQxOXgxNzkzMDkxMDg3MjU1NjIzNDYy parts=1218962026/10/27 08:51:30 INFO Received uploads request method=POST path=/api/pending_closures18972026/10/27 08:51:30 INFO Received uploads request method=POST path=/api/pending_closures18982026/10/27 08:51:30 INFO Received push request method=POST path=/api/pushes1899=== NAME TestOrphanedObjectsGC1900 orphaned_objects_gc_test.go:287: GC Test Summary:1901 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1902 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1903 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1904 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1905 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1906--- PASS: TestOrphanedObjectsGC (8.92s)1907=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19082026/10/27 08:51:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19092026/10/27 08:51:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjA0ODBhNzkxLWE3MmUtNGVjNy1iZWRjLWI4OGM5ODVlZGZmZXgxNzkzMDkxMDgzNTcxMTk1OTk4 parts=101910--- PASS: TestReadRedirectUsesPublicS3URL (8.08s)1911=== CONT TestParseSingleRange/multi-range_ignored1912=== CONT TestParseSingleRange/open-ended1913=== CONT TestParseSingleRange/start_far_past_EOF1914=== CONT TestParseSingleRange/start_past_EOF1915=== CONT TestParseSingleRange/suffix_exceeds_size1916=== CONT TestParseSingleRange/suffix1917=== CONT TestParseSingleRange/single_byte1918=== CONT TestParseSingleRange/end_clamped_to_size1919=== CONT TestParseSingleRange/closed1920=== CONT TestParseSingleRange/malformed_end_before_start1921=== CONT TestParseSingleRange/malformed_both_empty1922=== CONT TestParseSingleRange/unknown_unit1923=== CONT TestParseSingleRange/malformed_no_dash1924=== CONT TestParseSingleRange/none1925--- PASS: TestParseSingleRange (0.00s)1926 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1927 --- PASS: TestParseSingleRange/open-ended (0.00s)1928 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1929 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1930 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1931 --- PASS: TestParseSingleRange/suffix (0.00s)1932 --- PASS: TestParseSingleRange/single_byte (0.00s)1933 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1934 --- PASS: TestParseSingleRange/closed (0.00s)1935 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1936 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1937 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1938 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1939 --- PASS: TestParseSingleRange/none (0.00s)1940=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19412026/10/27 08:51:31 INFO Received uploads request method=POST path=/1942=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19432026/10/27 08:51:31 INFO Received complete multipart upload request method=POST path=/1944=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19452026/10/27 08:51:31 INFO Received request for more parts method=POST path=/1946=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19472026/10/27 08:51:31 INFO Received uploads request method=POST path=/1948--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1949 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1950 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1951 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1952 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1953=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19542026/10/27 08:51:31 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]1955=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1956=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19572026/10/27 08:51:31 WARN Authentication failed token_preview=eyJhbGciOi...uh37iLpqBQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1958=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1959=== CONT TestIsValidUploadKey/narinfo1960=== CONT TestIsValidUploadKey/unknown_type1961=== CONT TestIsValidUploadKey/realisation1962=== CONT TestIsValidUploadKey/empty_key1963=== CONT TestIsValidUploadKey/traversal_nar1964=== CONT TestIsValidUploadKey/traversal1965=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1966=== CONT TestIsValidUploadKey/absolute1967=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1968=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1969=== CONT TestIsValidUploadKey/nix-cache-info1970=== CONT TestIsValidUploadKey/realisation_plus_in_output1971=== CONT TestIsValidUploadKey/build_log1972=== CONT TestIsValidUploadKey/build_log_equals1973=== CONT TestIsValidUploadKey/index.html1974=== CONT TestIsValidUploadKey/build_log_plus_in_name1975=== CONT TestIsValidUploadKey/build_log_question_mark1976=== CONT TestIsValidUploadKey/nar_plain1977=== CONT TestIsValidUploadKey/listing1978=== CONT TestIsValidUploadKey/build_log_home-manager_file1979=== CONT TestIsValidUploadKey/nar_xz1980=== CONT TestIsValidUploadKey/nar_zst1981=== CONT TestService_RequireScope_OIDC/builder_may_write1982--- PASS: TestIsValidUploadKey (0.00s)1983 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1984 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1985 --- PASS: TestIsValidUploadKey/realisation (0.00s)1986 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1987 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1988 --- PASS: TestIsValidUploadKey/traversal (0.00s)1989 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1990 --- PASS: TestIsValidUploadKey/absolute (0.00s)1991 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1992 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1993 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1994 --- PASS: TestIsValidUploadKey/build_log (0.00s)1995 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1996 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1997 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1998 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1999 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2000 --- PASS: TestIsValidUploadKey/index.html (0.00s)2001 --- PASS: TestIsValidUploadKey/listing (0.00s)2002 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2003 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2004 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2005=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2006=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20072026/10/27 08:51:31 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]2008=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2009=== CONT TestService_RequireScope_OIDC/static_token_may_admin2010=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2011=== CONT TestService_RequireScope_OIDC/writer_implies_read2012=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2013=== CONT TestService_RequireScope_OIDC/static_token_may_write2014=== CONT TestService_RequireScope_OIDC/ops_may_not_write2015=== CONT TestService_RequireScope_OIDC/reader_may_read2016=== CONT TestService_RequireScope_OIDC/reader_may_not_write2017=== CONT TestService_RequireScope_OIDC/ops_may_admin2018=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2019=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20202026/10/27 08:51:31 INFO Received request for more parts method=POST path=/2021--- PASS: TestService_AuthMiddleware_OIDC (3.50s)2022 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2023 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2024 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2025 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2026--- PASS: TestService_RequireScope_OIDC (3.79s)2027 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.01s)2034 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20412026/10/27 08:51:32 INFO Received uploads request method=POST path=/api/pending_closures2042=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20432026/10/27 08:51:32 INFO Received complete multipart upload request method=POST path=/2044=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20452026/10/27 08:51:33 INFO Received uploads request method=POST path=/20462026/10/27 08:51:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20472026/10/27 08:51:33 INFO Aborted multipart uploads count=1 kept=020482026/10/27 08:51:33 INFO Received cleanup request method=DELETE path=/api/pending_closures20492026/10/27 08:51:33 INFO Aborted multipart uploads count=1 kept=020502026/10/27 08:51:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20512026/10/27 08:51:33 WARN Rate limiter enabled after throttle name=s3-test rate=520522026/10/27 08:51:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2053=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2054 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102055 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002056--- PASS: TestPendingCleanupUsesOneCutoff (9.07s)2057=== CONT TestPush_RejectsBadRequests/root_not_in_objects20582026/10/27 08:51:33 INFO Received push request method=POST path=/api/pushes2059=== CONT TestPush_RejectsBadRequests/no_roots20602026/10/27 08:51:33 INFO Received push request method=POST path=/api/pushes2061=== CONT TestPush_RejectsBadRequests/bad_root20622026/10/27 08:51:33 INFO Received push request method=POST path=/api/pushes2063=== CONT TestPush_RejectsBadRequests/no_objects20642026/10/27 08:51:33 INFO Received push request method=POST path=/api/pushes2065=== CONT TestProxyWriteTimeout/narinfo2066=== CONT TestProxyWriteTimeout/10_GiB_nar2067=== CONT TestProxyWriteTimeout/unknown_size2068=== CONT TestProxyWriteTimeout/1_GiB_nar2069--- PASS: TestProxyWriteTimeout (0.00s)2070 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2071 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2072 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2073 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2074=== CONT TestPendingClosureWriteTimeout/400_objects2075=== CONT TestPendingClosureWriteTimeout/670k_objects2076=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2077--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (9.19s)2078=== CONT TestPendingClosureWriteTimeout/empty2079=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2080--- PASS: TestPush_RejectsBadRequests (2.94s)2081 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2082 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2083 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2084 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)20852026/10/27 08:51:34 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjYyODA2NWIzLTFkZDYtNGVlZS04YjNmLWM3MDIwZDA1NDU3ZHgxNzkzMDkxMDkwMjE1MzgwODA5 error="Get \"http://127.0.0.1:1/bucket87/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20862026/10/27 08:51:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmVkNTI1ZTRjLTc3OTYtNDllOS1hMDgzLWZjMmZlMWMwYjZkYXgxNzkzMDkxMDkwMTU0NzYyNDM5 parts=1220872026-10-27 08:51:34.168 UTC [176] LOG: checkpoint starting: wal20882026/10/27 08:51:34 INFO Received cleanup request method=DELETE path=/api/pending_closures20892026/10/27 08:51:34 INFO Aborted multipart uploads count=1 kept=02090=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2091--- PASS: TestRedundantMultipartUpload (10.65s)2092=== CONT TestServerTLSConfig/not_a_PEM_file2093=== CONT TestServerTLSConfig/missing_CA_file2094=== CONT TestServerTLSConfig/no_client_CA2095--- PASS: TestServerTLSConfig (0.00s)2096 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2097 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2098 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)20992026/10/27 08:51:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21002026/10/27 08:51:35 INFO Aborted multipart uploads count=0 kept=021012026/10/27 08:51:35 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjE3MjI4ZGM0LTg1NzgtNDkxYy05OWE1LWI2NjJhMmQ0ZjViZHgxNzkzMDkxMDgzNTcwNDIzODky parts=1021022026/10/27 08:51:35 WARN Force mode enabled - objects will be deleted immediately without grace period21032026/10/27 08:51:35 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:35977/bucket99/?delete=\": context canceled"21042026-10-27 08:51:35.383 UTC [1723] LOG: unexpected EOF on client connection with an open transaction21052026/10/27 08:51:35 INFO Received uploads request method=POST path=/api/pending_closures21062026/10/27 08:51:36 INFO Received uploads request method=POST path=/api/pending_closures21072026/10/27 08:51:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21082026/10/27 08:51:36 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjFmZWU2NDQyLWUwOTctNDY5OC04OGRjLThkZDZmYWIyMjk5NHgxNzkzMDkxMDkyMzA0MTYzNTE5 parts=1221092026/10/27 08:51:36 INFO Received uploads request method=POST path=/api/pending_closures21102026/10/27 08:51:36 ERROR Failed to register completed object error="register completed object \"nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst\": timeout: context deadline exceeded" object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst2111=== NAME TestPush_CompleteCommitsEveryRoot2112 pushes_test.go:135: unexpected http status=500 body=failed to register completed object2113 2114 2115--- PASS: TestCompletedNarNotReofferedAcrossClosures (11.49s)2116--- PASS: TestPendingClosureWriteTimeout (0.00s)2117 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2118 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2119 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2120 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.90s)21212026/10/27 08:51:36 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=021222026/10/27 08:51:36 INFO Vacuumed table table=pending_closures21232026-10-27 08:51:36.838 UTC [1501] ERROR: canceling statement due to user request21242026-10-27 08:51:36.838 UTC [1501] STATEMENT: -- name: RegisterCompletedObject :exec2125 INSERT INTO objects (key, refs, size)2126 SELECT $1::varchar, $2::varchar [], $32127 WHERE EXISTS (SELECT 1 FROM pending_objects WHERE key = $1::varchar)2128 ON CONFLICT (key) DO UPDATE SET2129 refs = (2130 SELECT ARRAY(2131 SELECT DISTINCT unnest(objects.refs || excluded.refs)2132 )2133 ),2134 size = coalesce(objects.size, excluded.size),2135 deleted_at = NULL,2136 first_deleted_at = NULL2137 21382026/10/27 08:51:36 INFO Vacuumed table table=pending_objects21392026/10/27 08:51:36 INFO Vacuumed table table=multipart_uploads21402026/10/27 08:51:36 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmNmNDdkY2E4LTg5OTItNDViYy04OGVhLWI2ZWU2MWMxZGI1ZHgxNzkzMDkxMDk2MjgyOTI5Nzc2 error="Access Denied"21412026/10/27 08:51:36 WARN keeping failed pending closure for cleanup to retry the abort id=12142--- FAIL: TestPush_CompleteCommitsEveryRoot (16.71s)21432026/10/27 08:51:37 INFO Vacuumed table table=closures21442026/10/27 08:51:37 INFO Vacuumed table table=objects21452026/10/27 08:51:37 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002146--- PASS: TestService_createPendingClosureHandler (16.25s)21472026/10/27 08:51:37 WARN Force mode enabled - objects will be deleted immediately without grace period21482026-10-27 08:51:37.855 UTC [1671] ERROR: canceling statement due to user request21492026-10-27 08:51:37.855 UTC [1671] STATEMENT: -- name: MarkStaleObjects :execrows2150 WITH RECURSIVE ct AS (2151 SELECT timezone('UTC', now()) AS now2152 ),2153 closure_reach AS (2154 -- Start with all closure keys2155 SELECT o.key, o.refs2156 FROM objects o2157 INNER JOIN closures c ON o.key = c.key2158 UNION2159 -- Recursively add all referenced objects2160 SELECT o.key, o.refs2161 FROM objects o2162 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2163 ),2164 reachable_objects AS (2165 SELECT DISTINCT key FROM closure_reach2166 ),2167 stale_objects AS (2168 SELECT o.key2169 FROM objects AS o, ct2170 WHERE2171 NOT EXISTS (2172 SELECT 12173 FROM reachable_objects ro2174 WHERE ro.key = o.key2175 )2176 AND NOT EXISTS (2177 SELECT 12178 FROM pending_objects AS po2179 WHERE po.key = o.key2180 )2181 AND o.deleted_at IS NULL -- Only mark fresh objects2182 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2183 FOR UPDATE2184 )2185 UPDATE objects2186 SET2187 deleted_at = ct.now,2188 first_deleted_at = COALESCE(first_deleted_at, ct.now)2189 FROM stale_objects, ct2190 WHERE objects.key = stale_objects.key2191 21922026/10/27 08:51:37 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmEzZmM5ZTIwLTc4MjEtNGUyZS1iNzg5LTRjMzg5YmM5OTYxMHgxNzkzMDkxMDkwNjk4MDMzODEw parts=102193--- PASS: TestGCEndsOnShutdown (0.00s)2194 --- PASS: TestGCEndsOnShutdown/before_the_run (2.27s)2195 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (8.54s)2196 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (11.49s)21972026/10/27 08:51:38 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/present21982026/10/27 08:51:38 INFO Received push request method=POST path=/api/pushes2199--- PASS: TestConnectWaitsForAPeerMigration (23.90s)22002026/10/27 08:51:38 WARN Request failed, retrying attempt=2 backoff=209.703851ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22012026/10/27 08:51:38 INFO Object in database but missing from S3 key=kpcv8jfqfg3lk43a8g75pifvqrbplnxa.ls22022026/10/27 08:51:38 WARN Found objects in DB but missing from S3, will re-upload count=122032026/10/27 08:51:38 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22042026/10/27 08:51:38 WARN Request failed, retrying attempt=3 backoff=391.03975ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22052026/10/27 08:51:38 INFO Received push request method=POST path=/api/pushes22062026/10/27 08:51:38 WARN Request failed, retrying attempt=4 backoff=816.493784ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22072026/10/27 08:51:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22082026/10/27 08:51:38 INFO Uploading qzl050qahsdjzk52d0wfc29jn8q0rz76-ca-test (144B)22092026/10/27 08:51:38 INFO Received push request method=POST path=/api/pushes22102026/10/27 08:51:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22112026/10/27 08:51:39 INFO Uploading 98clw4f62sqd62kdhlphra7398haq9w1-unpinned-file.txt (128B)22122026/10/27 08:51:39 INFO Received complete push request method=POST path=/api/pushes/2/complete22132026/10/27 08:51:39 WARN Failed to register uploaded object key=kpcv8jfqfg3lk43a8g75pifvqrbplnxa.ls error="server returned 404: 404 page not found\n"22142026/10/27 08:51:39 INFO Completed push id=2 objects=3 duration=22.393256ms22152026/10/27 08:51:39 INFO Upload complete. (2.426s)2216=== NAME TestClientIntegration2217 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)2218 client_integration_test.go:375: Decompressed .ls content (49 bytes):2219 {"version":1,"root":{"type":"regular","size":39}}22202026/10/27 08:51:39 WARN Failed to register uploaded object key=log/63qbcjliqdx9invz6lsgfby6g3m319nm-ca-test.drv error="server returned 404: 404 page not found\n"22212026/10/27 08:51:39 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"22222026/10/27 08:51:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22232026/10/27 08:51:39 WARN Failed to register uploaded object key=qzl050qahsdjzk52d0wfc29jn8q0rz76.ls error="server returned 404: 404 page not found\n"22242026/10/27 08:51:39 INFO Signed narinfos id=1 count=122252026/10/27 08:51:39 INFO Uploading 1 narinfos22262026/10/27 08:51:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"22272026/10/27 08:51:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22282026/10/27 08:51:39 WARN Request failed, retrying attempt=5 backoff=1.726598622s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22292026/10/27 08:51:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign22302026/10/27 08:51:39 WARN Failed to register uploaded object key=98clw4f62sqd62kdhlphra7398haq9w1.ls error="server returned 404: 404 page not found\n"22312026/10/27 08:51:39 INFO Signed narinfos id=2 count=122322026/10/27 08:51:39 INFO Uploading 1 narinfos22332026/10/27 08:51:39 INFO Received complete push request method=POST path=/api/pushes/1/complete22342026/10/27 08:51:39 WARN Failed to register uploaded object key=qzl050qahsdjzk52d0wfc29jn8q0rz76.narinfo error="server returned 404: 404 page not found\n"22352026/10/27 08:51:39 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjFlNzFmNzU1LTQ1YTAtNDg3My1hNTk0LTdiMzUxMGQ3N2VlZXgxNzkzMDkxMDgzNTY2MzE5NDk2 parts=1022362026/10/27 08:51:39 INFO Completed push id=1 objects=4 duration=16.858187ms22372026/10/27 08:51:39 INFO Upload complete. (1.712s)22382026/10/27 08:51:39 INFO Received complete push request method=POST path=/api/pushes/2/complete22392026/10/27 08:51:39 WARN Failed to register uploaded object key=98clw4f62sqd62kdhlphra7398haq9w1.narinfo error="server returned 404: 404 page not found\n"22402026/10/27 08:51:39 INFO Completed push id=2 objects=3 duration=9.535183ms22412026/10/27 08:51:39 INFO Upload complete. (1.632s)2242=== NAME TestClientCADerivations2243 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3939792872/001/store/qzl050qahsdjzk52d0wfc29jn8q0rz76-ca-test2244 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2245 Compression: zstd2246 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2247 NarSize: 1442248 References: 2249 Deriver: /build/TestClientCADerivations3939792872/001/store/63qbcjliqdx9invz6lsgfby6g3m319nm-ca-test.drv2250 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2251 client_ca_test.go:185: Checking for realisation files in S3...2252 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2253 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache22542026/10/27 08:51:39 INFO Received uploads request method=POST path=/api/pending_closures22552026/10/27 08:51:39 INFO Aborted multipart uploads count=0 kept=022562026/10/27 08:51:39 WARN Force mode enabled - objects will be deleted immediately without grace period22572026/10/27 08:51:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures22582026/10/27 08:51:39 INFO Garbage collection started22592026/10/27 08:51:39 INFO Aborted multipart uploads count=0 kept=022602026/10/27 08:51:40 WARN Force mode enabled - objects will be deleted immediately without grace period22612026/10/27 08:51:40 INFO Received uploads request method=POST path=/api/pending_closures22622026/10/27 08:51:40 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=022632026/10/27 08:51:40 INFO Vacuumed table table=pending_closures22642026/10/27 08:51:40 INFO Vacuumed table table=pending_objects22652026/10/27 08:51:40 INFO Vacuumed table table=multipart_uploads22662026/10/27 08:51:40 INFO Vacuumed table table=closures22672026/10/27 08:51:40 INFO Vacuumed table table=objects22682026/10/27 08:51:40 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=022692026/10/27 08:51:40 INFO Received push request method=POST path=/api/pushes22702026/10/27 08:51:40 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22712026/10/27 08:51:40 INFO Vacuumed table table=pending_closures2272--- PASS: TestReadRedirectNar (14.75s)22732026/10/27 08:51:40 INFO Vacuumed table table=pending_objects22742026/10/27 08:51:40 INFO Vacuumed table table=multipart_uploads22752026/10/27 08:51:40 INFO Vacuumed table table=closures22762026/10/27 08:51:40 INFO Vacuumed table table=objects22772026/10/27 08:51:40 INFO Received complete push request method=POST path=/api/pushes/3/complete22782026/10/27 08:51:40 WARN Failed to register uploaded object key=kpcv8jfqfg3lk43a8g75pifvqrbplnxa.ls error="server returned 404: 404 page not found\n"22792026/10/27 08:51:40 INFO Completed push id=3 objects=3 duration=3.207048ms22802026/10/27 08:51:40 INFO Upload complete. (599ms)2281=== NAME TestClientIntegration2282 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)2283 client_integration_test.go:392: Decompressed .ls content (49 bytes):2284 {"version":1,"root":{"type":"regular","size":39}}2285--- PASS: TestPendingClosureFailureTracksEveryUpload (0.01s)2286 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (3.13s)2287 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (6.62s)22882026/10/27 08:51:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22892026/10/27 08:51:41 INFO Received uploads request method=POST path=/api/pending_closures22902026/10/27 08:51:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22912026/10/27 08:51:41 INFO Aborted multipart uploads count=0 kept=022922026/10/27 08:51:41 WARN Force mode enabled - objects will be deleted immediately without grace period22932026/10/27 08:51:41 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLjcwZGUyN2YyLTc3OWQtNGJmZi05YzBmLThkZmUzMTk4ZmE0YngxNzkzMDkxMDkwNjk2OTgxOTIx parts=1022942026/10/27 08:51:41 INFO Received complete push request method=POST path=/api/pushes/1/complete22952026/10/27 08:51:41 INFO Completed push id=1 objects=4 duration=16.648385ms22962026/10/27 08:51:41 INFO Received push request method=POST path=/api/pushes22972026/10/27 08:51:41 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=02298--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2299 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (2.08s)2300 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (11.95s)23012026/10/27 08:51:41 INFO Vacuumed table table=pending_closures23022026/10/27 08:51:41 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23032026/10/27 08:51:41 INFO Vacuumed table table=pending_objects23042026/10/27 08:51:41 INFO Vacuumed table table=multipart_uploads23052026/10/27 08:51:41 INFO Vacuumed table table=closures23062026/10/27 08:51:41 INFO Vacuumed table table=objects23072026/10/27 08:51:41 INFO Aborted multipart uploads count=0 kept=023082026/10/27 08:51:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023092026/10/27 08:51:41 WARN Force mode enabled - objects will be deleted immediately without grace period23102026/10/27 08:51:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23112026/10/27 08:51:41 WARN Request failed, retrying attempt=2 backoff=196.39662ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23122026/10/27 08:51:42 INFO Received create pin request method=POST path=/api/pins/myapp23132026/10/27 08:51:42 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3913271367/001/store/7yagqwfhkb9snqirn2rypwqjrmn9s18z-pinned-file.txt narinfo_key=7yagqwfhkb9snqirn2rypwqjrmn9s18z.narinfo23142026/10/27 08:51:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures23152026/10/27 08:51:42 INFO Garbage collection started23162026/10/27 08:51:42 INFO Aborted multipart uploads count=0 kept=023172026/10/27 08:51:42 WARN Force mode enabled - objects will be deleted immediately without grace period23182026/10/27 08:51:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023192026/10/27 08:51:42 INFO Vacuumed table table=pending_closures23202026/10/27 08:51:42 INFO Vacuumed table table=pending_objects23212026/10/27 08:51:42 INFO Vacuumed table table=multipart_uploads23222026/10/27 08:51:42 INFO Vacuumed table table=closures23232026/10/27 08:51:42 INFO Received push request method=POST path=/api/pushes2324--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2325 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (13.52s)2326 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (14.93s)23272026/10/27 08:51:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23282026/10/27 08:51:42 INFO Vacuumed table table=objects23292026/10/27 08:51:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23302026/10/27 08:51:42 INFO Uploading kks5rn8f3k734v698lpymnl96rqs0yfc-lost-commit.txt (152B)23312026/10/27 08:51:42 WARN Request failed, retrying attempt=3 backoff=369.424424ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23322026/10/27 08:51:42 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"23332026/10/27 08:51:42 WARN Request failed, retrying attempt=4 backoff=836.00565ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23342026/10/27 08:51:42 WARN Failed to register uploaded object key=kks5rn8f3k734v698lpymnl96rqs0yfc.ls error="server returned 404: 404 page not found\n"23352026/10/27 08:51:42 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign23362026/10/27 08:51:42 INFO Signed narinfos id=4 count=123372026/10/27 08:51:42 INFO Uploading 1 narinfos23382026/10/27 08:51:42 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmU4NjY3YzVkLWQ3NTMtNDE5OS04YmY5LThjNGVkZjA4N2RjMXgxNzkzMDkxMDgzNTcxMDIzMDE3 parts=1023392026/10/27 08:51:42 INFO Received complete push request method=POST path=/api/pushes/4/complete23402026/10/27 08:51:42 WARN Failed to register uploaded object key=kks5rn8f3k734v698lpymnl96rqs0yfc.narinfo error="server returned 404: 404 page not found\n"23412026/10/27 08:51:42 INFO Completed push id=4 objects=3 duration=2.394321ms23422026/10/27 08:51:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:36643/api/pushes/4/complete\": EOF" url=http://127.0.0.1:36643/api/pushes/4/complete23432026/10/27 08:51:42 INFO Received complete push request method=POST path=/api/pushes/4/complete23442026-10-27 08:51:42.953 UTC [846] ERROR: Push does not exist: id=423452026-10-27 08:51:42.953 UTC [846] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE23462026-10-27 08:51:42.953 UTC [846] STATEMENT: -- name: CommitPush :one2347 SELECT commit_push($1::bigint)::bigint2348 23492026/10/27 08:51:42 WARN Push not found id=423502026/10/27 08:51:42 INFO Upload complete. (2.005s)2351=== NAME TestClientIntegration2352 client_integration_test.go:422: Retrieved narinfo from S3:2353 StorePath: /build/TestClientIntegration356371126/002/store/kks5rn8f3k734v698lpymnl96rqs0yfc-lost-commit.txt2354 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2355 Compression: zstd2356 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2357 NarSize: 1522358 References: 2359 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2360 client_integration_test.go:425: Testing garbage collection...23612026-10-27 08:51:43.404 UTC [1399] ERROR: could not obtain lock on row in relation "closures"23622026-10-27 08:51:43.404 UTC [1399] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23632026-10-27 08:51:43.404 UTC [1399] ERROR: could not obtain lock on row in relation "closures"23642026-10-27 08:51:43.404 UTC [1399] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23652026-10-27 08:51:43.405 UTC [1399] ERROR: could not obtain lock on row in relation "closures"23662026-10-27 08:51:43.405 UTC [1399] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23672026-10-27 08:51:43.406 UTC [1399] ERROR: could not obtain lock on row in relation "closures"23682026-10-27 08:51:43.406 UTC [1399] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23692026-10-27 08:51:43.406 UTC [1399] ERROR: could not obtain lock on row in relation "closures"23702026-10-27 08:51:43.406 UTC [1399] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23712026/10/27 08:51:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures23722026/10/27 08:51:43 INFO Garbage collection started2373--- PASS: TestPush_RootsAreLockedInByteOrder (22.96s)23742026/10/27 08:51:43 INFO Aborted multipart uploads count=0 kept=023752026/10/27 08:51:43 WARN Force mode enabled - objects will be deleted immediately without grace period23762026/10/27 08:51:43 WARN Request failed, retrying attempt=5 backoff=1.542293913s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23772026/10/27 08:51:43 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=023782026/10/27 08:51:43 INFO Vacuumed table table=pending_closures23792026/10/27 08:51:43 INFO Vacuumed table table=pending_objects23802026/10/27 08:51:43 INFO Vacuumed table table=multipart_uploads23812026/10/27 08:51:43 INFO Vacuumed table table=closures23822026/10/27 08:51:43 INFO Vacuumed table table=objects2383=== NAME TestOrphanedObjectsGCStressTest2384 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2385 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2386=== NAME TestPinProtectsFromGC2387 client_integration_test.go:963: Pin successfully protected closure from garbage collection2388--- PASS: TestPinProtectsFromGC (28.76s)23892026/10/27 08:51:44 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=023902026/10/27 08:51:44 INFO Vacuumed table table=pending_closures23912026/10/27 08:51:44 INFO Vacuumed table table=pending_objects23922026/10/27 08:51:44 INFO Vacuumed table table=multipart_uploads23932026/10/27 08:51:44 INFO Vacuumed table table=closures23942026/10/27 08:51:44 INFO Vacuumed table table=objects23952026/10/27 08:51:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23962026/10/27 08:51:44 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZDRhZWFhZjgtYjAzNy00MzEzLWFhMDItNTNhY2NlMDQzMDFkLmU1Yzk0ODMyLWE5NGQtNDE1My04MzU4LWUyNmJhNDQ2OWJmM3gxNzkzMDkxMTAxODUxMDQ2NDc1 parts=1023972026/10/27 08:51:44 INFO Received complete push request method=POST path=/api/pushes/2/complete23982026/10/27 08:51:44 INFO Completed push id=2 objects=4 duration=2.472301ms2399--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (19.30s)2400=== NAME TestOrphanedObjectsGCStressTest2401 orphaned_objects_gc_test.go:503: Stress test completed successfully:2402 orphaned_objects_gc_test.go:504: - Active objects preserved: 202403 orphaned_objects_gc_test.go:505: - Objects deleted: 2102404 orphaned_objects_gc_test.go:506: - Total GC'd: 2102405--- PASS: TestOrphanedObjectsGCStressTest (22.13s)24062026/10/27 08:51:45 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"24072026/10/27 08:51:45 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-config24082026/10/27 08:51:45 WARN Request failed, retrying attempt=2 backoff=194.622681ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24092026/10/27 08:51:45 WARN Request failed, retrying attempt=3 backoff=437.739318ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/27 08:51:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02411=== NAME TestClientIntegration2412 client_integration_test.go:432: Objects in database after GC:2413 client_integration_test.go:432: Successfully deleted all objects with GC --force2414--- PASS: TestClientIntegration (27.97s)24152026/10/27 08:51:45 WARN Request failed, retrying attempt=4 backoff=782.233536ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2416=== NAME TestClientCADerivations2417 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2418 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2419 error: binary cache 's3://bucket58?endpoint=http://localhost:35977®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3939792872/001/store'2420 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12421--- PASS: TestClientCADerivations (29.46s)24222026/10/27 08:51:46 WARN Request failed, retrying attempt=5 backoff=1.692873251s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24232026/10/27 08:51:48 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_closures24242026/10/27 08:51:48 WARN Request failed, retrying attempt=2 backoff=219.936456ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24252026/10/27 08:51:48 WARN Request failed, retrying attempt=3 backoff=373.957913ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24262026/10/27 08:51:49 WARN Request failed, retrying attempt=4 backoff=847.77411ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24272026/10/27 08:51:49 WARN Request failed, retrying attempt=5 backoff=1.534820547s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2428--- PASS: TestUploadHandlersRejectOversizedBody (0.50s)2429 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (1.12s)2430 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (1.32s)2431 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (17.26s)2432--- PASS: TestClientErrorHandling (0.00s)2433 --- PASS: TestClientErrorHandling/InvalidStorePath (12.41s)2434 --- PASS: TestClientErrorHandling/InvalidAuthToken (14.79s)2435 --- PASS: TestClientErrorHandling/ServerNotAvailable (23.28s)2436FAIL24372026-10-27 08:51:51.748 UTC [171] LOG: received smart shutdown request24382026-10-27 08:51:51.751 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 124392026-10-27 08:51:52.295 UTC [176] LOG: checkpoint complete: wrote 9473 buffers (57.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=17.718 s, sync=0.253 s, total=18.127 s; sync files=37078, longest=0.001 s, average=0.001 s; distance=534230 kB, estimate=534230 kB; lsn=0/22BD2B28, redo lsn=0/2211B86024402026-10-27 08:51:52.301 UTC [176] LOG: shutting down24412026-10-27 08:51:52.301 UTC [176] LOG: checkpoint starting: shutdown immediate24422026-10-27 08:51:52.412 UTC [176] LOG: checkpoint complete: wrote 1598 buffers (9.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.039 s, sync=0.069 s, total=0.112 s; sync files=711, longest=0.002 s, average=0.001 s; distance=10972 kB, estimate=481905 kB; lsn=0/22BD2BA0, redo lsn=0/22BD2BA024432026-10-27 08:51:52.499 UTC [171] LOG: database system is shut down