niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #360
· 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_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 138 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.58s)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 TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestStreamPushStopsOnCancel129=== CONT TestCompletePendingClosure_NotFoundWithoutKey130=== CONT TestDoWithRetry_FinalResponseBodyReadable131=== CONT TestStreamPushReportsEveryPath132=== CONT TestDumpPathWriterError133=== CONT TestFileTokenEmpty134=== CONT TestStreamPushReportsSignatures135=== CONT TestScriptTokenDoesNotWaitForItsChildren136=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs137=== CONT TestStreamPushRequestLine138=== CONT TestScriptTokenEmptyCommand139=== CONT TestClientSignaturesByStorePath140=== CONT TestScriptTokenCachesUntilRefresh141=== CONT TestScriptTokenScriptFails142=== CONT TestSetClientTLSErrors143=== CONT TestUploadMultipart_ProducerErrorIsNotEOF144=== CONT TestStreamPushBatchesUnderLoad145=== RUN TestStreamPushBatchesUnderLoad/together146=== CONT TestTruncatedNARDumpIsNotCompleted147=== RUN TestStreamPushStopsOnCancel/waiting_for_input148=== CONT TestDoServerRequestAttachesToken149=== CONT TestDumpPathSingleFile150=== CONT TestGetStorePathHash151=== CONT TestDumpPathMatchesNix152=== CONT TestCaseHackSuffix153=== CONT TestFilterOversizedClosures154=== CONT TestResolveStorePath155--- PASS: TestScriptTokenEmptyCommand (0.00s)156=== CONT TestPathInfoCACompatibility157=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs158=== CONT TestConvertHashToNix32159=== CONT TestSetClientTLS160=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part161=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part162=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout163--- PASS: TestClientSignaturesByStorePath (0.00s)164--- PASS: TestFileTokenEmpty (0.00s)165=== RUN TestConvertHashToNix32/SRI_format_to_Nix32166=== CONT TestRegisterUploadedObjectReusesConnections167=== PAUSE TestStreamPushBatchesUnderLoad/together168=== RUN TestGetStorePathHash/valid_store_path169=== RUN TestFilterOversizedClosures/no_limit_keeps_everything170=== RUN TestPathInfoCACompatibility/null_ca_field171=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input172--- PASS: TestScriptTokenScriptFails (0.00s)173=== RUN TestSetClientTLSErrors/missing_cert_file174=== CONT TestFileTokenMissing175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== PAUSE TestSetClientTLSErrors/missing_cert_file177=== RUN TestSetClientTLSErrors/missing_key_file178=== PAUSE TestSetClientTLSErrors/missing_key_file179=== RUN TestSetClientTLSErrors/missing_ca_file180=== CONT TestScriptTokenEmptyToken181=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess182=== CONT TestFileTokenReadsAndCaches183=== PAUSE TestSetClientTLSErrors/missing_ca_file184=== CONT TestRateLimiterFeedback185=== RUN TestRateLimiterFeedback/429_enables_limiter186=== PAUSE TestRateLimiterFeedback/429_enables_limiter187=== RUN TestConvertHashToNix32/already_Nix32_format188=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time189=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time190=== PAUSE TestConvertHashToNix32/already_Nix32_format191=== RUN TestConvertHashToNix32/invalid_format192=== PAUSE TestConvertHashToNix32/invalid_format193=== CONT TestScriptTokenBadJSON194=== CONT TestScriptTokenNoExpiryRerunsEveryCall195=== CONT TestStreamPushIsolatesFailures196=== PAUSE TestGetStorePathHash/valid_store_path197=== RUN TestGetStorePathHash/basename_without_hyphen_should_error198=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error199=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error200=== CONT TestEncodeNixBase32WithRealHash201=== CONT TestShellSplitErrors202=== CONT TestSetClientTLSDoesNotMutateDefaultTransport203=== CONT TestShellSplit204=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer205=== CONT TestDoWithRetry_BodyReplayedViaGetBody206=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure207=== RUN TestSetClientTLS/rejects_connection_without_client_cert208=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert209=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA210=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA211=== RUN TestSetClientTLS/preserves_debug_logging_transport212=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error213=== PAUSE TestPathInfoCACompatibility/null_ca_field214=== CONT TestUploadMultipart_PartsInParallel215=== PAUSE TestSetClientTLS/preserves_debug_logging_transport216=== CONT TestSupersededNARStillUploadsListing217=== RUN TestSupersededNARStillUploadsListing/small_NAR218=== PAUSE TestSupersededNARStillUploadsListing/small_NAR219=== RUN TestSupersededNARStillUploadsListing/dump_cut_short220=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short221=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails222=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails223=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry224=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error225=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything226--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)227=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot228--- PASS: TestResolveStorePath (0.00s)229=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary230=== RUN TestSetClientTLSErrors/invalid_ca_file231=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout232=== RUN TestRateLimiterFeedback/503_enables_limiter233=== CONT TestStaticToken234=== CONT TestStreamPushGivesUpOnDeadServer235=== RUN TestPathInfoCACompatibility/old_string_format_-_text236=== CONT TestEncodeNixBase32237=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary240=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot241=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot242=== PAUSE TestSetClientTLSErrors/invalid_ca_file243=== PAUSE TestRateLimiterFeedback/503_enables_limiter244=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent245=== CONT TestPartSizeForNAR246=== RUN TestPartSizeForNAR/zero_stays_at_minimum247=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot248=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot249=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot250=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot251=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot252=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken253=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier254=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped255=== CONT TestUploadMultipart_SupersededByPeer256=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier257=== RUN TestUploadMultipart_SupersededByPeer/exists258=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text259=== PAUSE TestUploadMultipart_SupersededByPeer/exists260=== RUN TestEncodeNixBase32/test_string_hash261=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica262=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun263=== CONT TestUploadMultipart_FailedPartBufferNotReused264--- PASS: TestStreamPushReportsEveryPath (0.01s)265=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter266=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum267=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken268=== RUN TestFilterOversizedClosures/all_closures_skipped269=== CONT TestPathInfoHashCompatibility270=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up271=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)272=== PAUSE TestFilterOversizedClosures/all_closures_skipped273=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter274=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)275=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter276=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up277=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon278=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter279=== CONT TestConvertHashToNix32/SRI_format_to_Nix32280=== CONT TestConvertHashToNix32/already_Nix32_format281--- PASS: TestStreamPushReportsSignatures (0.25s)282=== PAUSE TestEncodeNixBase32/test_string_hash283=== CONT TestParsePathInfoJSONMultiplePaths284=== RUN TestPartSizeForNAR/small_stays_at_minimum285=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== RUN TestUploadMultipart_SupersededByPeer/missing287=== CONT TestParsePathInfoJSON288=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon289=== PAUSE TestUploadMultipart_SupersededByPeer/missing290=== CONT TestStreamPushBatchesUnderLoad/together291=== RUN TestParsePathInfoJSON/Nix_format292=== PAUSE TestPartSizeForNAR/small_stays_at_minimum293=== PAUSE TestParsePathInfoJSON/Nix_format294=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths296--- PASS: TestFileTokenMissing (0.00s)297=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI298=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths299=== RUN TestPathInfoCACompatibility/new_structured_format_-_text300=== RUN TestParsePathInfoJSON/Lix_format301=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI302=== PAUSE TestParsePathInfoJSON/Lix_format303=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== RUN TestParsePathInfoJSON/empty_input305=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths306=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text307=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum308=== CONT TestConvertHashToNix32/invalid_format309=== PAUSE TestParsePathInfoJSON/empty_input310=== RUN TestEncodeNixBase32/empty_input311=== CONT TestSetClientTLS/rejects_connection_without_client_cert312=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum314=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method315=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts316--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.25s)317--- PASS: TestDoServerRequestAttachesToken (0.25s)318=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts319--- PASS: TestFileTokenReadsAndCaches (0.00s)320--- PASS: TestStreamPushIsolatesFailures (0.00s)321--- PASS: TestEncodeNixBase32WithRealHash (0.00s)322--- PASS: TestShellSplitErrors (0.00s)323--- PASS: TestScriptTokenEmptyToken (0.00s)324--- PASS: TestShellSplit (0.00s)325=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512326--- PASS: TestScriptTokenBadJSON (0.00s)327--- PASS: TestScriptTokenCachesUntilRefresh (0.25s)328--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)329=== RUN TestParsePathInfoJSON/whitespace_only330=== PAUSE TestParsePathInfoJSON/whitespace_only331=== CONT TestSetClientTLS/preserves_debug_logging_transport332--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)333=== RUN TestParsePathInfoJSON/invalid_JSON334=== PAUSE TestEncodeNixBase32/empty_input335=== CONT TestSupersededNARStillUploadsListing/small_NAR336=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths337=== RUN TestPartSizeForNAR/1_TiB338=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails339=== PAUSE TestPartSizeForNAR/1_TiB340=== RUN TestPartSizeForNAR/5_TiB_S3_max_object341=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object342=== RUN TestPartSizeForNAR/capped_at_5_GiB343=== PAUSE TestPartSizeForNAR/capped_at_5_GiB344=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs345--- PASS: TestStaticToken (0.00s)346--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)347=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA348--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)349--- PASS: TestConvertHashToNix32 (0.25s)350 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)351 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)352 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)353=== PAUSE TestParsePathInfoJSON/invalid_JSON354=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time355=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout356=== CONT TestSupersededNARStillUploadsListing/dump_cut_short357--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)358=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part359=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error360--- PASS: TestStreamPushBatchesUnderLoad (0.25s)361 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)362 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)363=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary364--- PASS: TestDumpPathSingleFile (0.54s)365=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error366=== CONT TestGetStorePathHash/basename_without_hyphen_should_error367--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.27s)368=== CONT TestGetStorePathHash/valid_store_path369=== CONT TestSetClientTLSErrors/invalid_ca_file370=== CONT TestSetClientTLSErrors/missing_ca_file371=== CONT TestSetClientTLSErrors/missing_cert_file372=== CONT TestSetClientTLSErrors/missing_key_file373--- PASS: TestCaseHackSuffix (0.54s)374=== CONT TestStreamPushStopsOnCancel/waiting_for_input375=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot376=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot377=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken378--- PASS: TestGetStorePathHash (0.26s)379 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)380 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)381 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)382 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)383--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.28s)384--- PASS: TestSetClientTLSErrors (0.27s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot390=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot391=== CONT TestFilterOversizedClosures/all_closures_skipped392=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped393=== CONT TestFilterOversizedClosures/no_limit_keeps_everything394=== CONT TestRateLimiterFeedback/429_enables_limiter395--- PASS: TestFilterOversizedClosures (0.02s)396 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)397 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)398 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)399=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier400=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up401=== CONT TestRateLimiterFeedback/503_enables_limiter402=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter403=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter404--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)405 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)406 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)407=== CONT TestUploadMultipart_SupersededByPeer/exists408=== CONT TestUploadMultipart_SupersededByPeer/missing409--- PASS: TestRateLimiterFeedback (0.02s)410 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)413 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)414=== CONT TestPathInfoCACompatibility/null_ca_field415=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method416=== CONT TestPathInfoCACompatibility/new_structured_format_-_text417--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)418 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)419 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)420--- PASS: TestDumpPathWriterError (0.57s)421=== CONT TestPathInfoCACompatibility/old_string_format_-_text422=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512423=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive424=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon425=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)426--- PASS: TestPathInfoCACompatibility (0.27s)427 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)428 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)429 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)430 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)431 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)432=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI433=== CONT TestEncodeNixBase32/test_string_hash434=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths435=== CONT TestEncodeNixBase32/empty_input436--- PASS: TestPathInfoHashCompatibility (0.00s)437 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)438 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)439 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)440 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)441=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths442--- PASS: TestEncodeNixBase32 (0.01s)443 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)444 --- PASS: TestEncodeNixBase32/empty_input (0.00s)445=== CONT TestPartSizeForNAR/5_TiB_S3_max_object446=== CONT TestPartSizeForNAR/capped_at_5_GiB447=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts448=== CONT TestPartSizeForNAR/1_TiB449=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum450=== CONT TestPartSizeForNAR/zero_stays_at_minimum451--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)452 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)453 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)454=== CONT TestParsePathInfoJSON/whitespace_only455=== CONT TestParsePathInfoJSON/Nix_format456=== CONT TestParsePathInfoJSON/invalid_JSON457=== CONT TestParsePathInfoJSON/empty_input458=== CONT TestPartSizeForNAR/small_stays_at_minimum459=== CONT TestParsePathInfoJSON/Lix_format460--- PASS: TestPartSizeForNAR (0.01s)461 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)462 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)463 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)464 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)465 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)466 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)467 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)468--- PASS: TestParsePathInfoJSON (0.01s)469 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)470 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)471 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)472 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)473 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)474--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.33s)475--- PASS: TestStreamPushStopsOnCancel (0.27s)476 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)480 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)482--- PASS: TestSetClientTLS (0.01s)483 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.28s)484 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.28s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.35s)486--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.26s)487 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.32s)488 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.47s)489--- PASS: TestRegisterUploadedObjectReusesConnections (0.52s)490--- PASS: TestDumpPathMatchesNix (0.78s)491--- PASS: TestStreamPushRequestLine (0.81s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestUploadMultipart_PartsInParallel (1.10s)494--- PASS: TestSupersededNARStillUploadsListing (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.27s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.28s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.11s)498--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.12s)499--- PASS: TestTruncatedNARDumpIsNotCompleted (1.44s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.27s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.27s)504PASS505Running server tests...506The files belonging to this database system will be owned by user "nixbld".507This user must also own the server process.508509The database cluster will be initialized with locale "C".510The default database encoding has accordingly been set to "SQL_ASCII".511The default text search configuration will be set to "english".512513Data page checksums are enabled.514515creating directory /build/postgres3230868478/data ... ok516creating subdirectories ... ok517selecting dynamic shared memory implementation ... posix518selecting default "max_connections" ... 100519selecting default "shared_buffers" ... 128MB520selecting default time zone ... UTC521creating configuration files ... ok522running bootstrap script ... ok523performing post-bootstrap initialization ... ok524syncing data to disk ... ok525526initdb: warning: enabling "trust" authentication for local connections527initdb: 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.528529Success. You can now start the database server using:530531 pg_ctl -D /build/postgres3230868478/data -l logfile start532533/build/postgres3230868478:5432 - no response5342026-10-05 12:09:31.359 UTC [175] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-05 12:09:31.359 UTC [175] LOG: listening on Unix socket "/build/postgres3230868478/.s.PGSQL.5432"5362026-10-05 12:09:31.363 UTC [182] LOG: database system was shut down at 2026-10-05 12:09:31 UTC5372026-10-05 12:09:31.367 UTC [175] LOG: database system is ready to accept connections538/build/postgres3230868478:5432 - accepting connections539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/10/05 12:09:31 INFO lead: acquired remote=192.0.2.1:12345872026/10/05 12:09:32 INFO lead: released remote=192.0.2.1:12345882026/10/05 12:09:32 INFO lead: acquired remote=192.0.2.1:12345892026/10/05 12:09:33 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)591=== RUN TestLeadIncumbentAnnouncesAtOnce592=== PAUSE TestLeadIncumbentAnnouncesAtOnce593=== RUN TestLeadEndsOnShutdown594=== PAUSE TestLeadEndsOnShutdown595=== RUN TestLeadEndsWhenItsConnectionHangs5962026/10/05 12:09:33 INFO lead: acquired remote=192.0.2.1:12345972026-10-05 12:09:35.059 UTC [430] FATAL: terminating connection due to administrator command5982026/10/05 12:09:35 INFO lead: acquired remote=192.0.2.1:12345992026/10/05 12:09:36 WARN lead: lock connection lost error="timeout: context deadline exceeded"6002026/10/05 12:09:36 INFO lead: released remote=192.0.2.1:12346012026/10/05 12:09:36 INFO lead: released remote=192.0.2.1:1234602--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)603=== RUN TestGCAdvisoryLockBlocksConcurrentRun604=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun605=== RUN TestGCBugBareHashReferences606=== PAUSE TestGCBugBareHashReferences607=== RUN TestGCMetrics608=== PAUSE TestGCMetrics609=== RUN TestPushDedupSurvivesConcurrentGC610=== PAUSE TestPushDedupSurvivesConcurrentGC611=== RUN TestDeduplicatedObjectsRecordedAsPending612=== PAUSE TestDeduplicatedObjectsRecordedAsPending613=== RUN TestGCSweepSkipsPendingObjects614=== PAUSE TestGCSweepSkipsPendingObjects615=== RUN TestTombstonedObjectOfferedWithoutWaiting616=== PAUSE TestTombstonedObjectOfferedWithoutWaiting617=== RUN TestGCSweepDeliversEachKeyOnce618=== PAUSE TestGCSweepDeliversEachKeyOnce619=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection621=== RUN TestForceGCDuringPushOffersSweptObject622=== PAUSE TestForceGCDuringPushOffersSweptObject623=== RUN TestFailedS3DeleteKeepsTombstone624=== PAUSE TestFailedS3DeleteKeepsTombstone625=== RUN TestSweepSkipsRowsLockedByPush626=== PAUSE TestSweepSkipsRowsLockedByPush627=== RUN TestRegisterCompletedObjectNeedsPendingRow628=== PAUSE TestRegisterCompletedObjectNeedsPendingRow629=== RUN TestGetExistingObjectsLocksRows630=== PAUSE TestGetExistingObjectsLocksRows631=== RUN TestSweepRechecksPendingAfterLocking632=== PAUSE TestSweepRechecksPendingAfterLocking633=== RUN TestPushWaitsForSweepHoldingRow634=== PAUSE TestPushWaitsForSweepHoldingRow635=== RUN TestCommitRacingPendingCleanupKeepsObjects636=== PAUSE TestCommitRacingPendingCleanupKeepsObjects637=== RUN TestGCEndsOnShutdown638=== PAUSE TestGCEndsOnShutdown639=== RUN TestGCTaskStore_StartNew640=== PAUSE TestGCTaskStore_StartNew641=== RUN TestGCTaskStore_DeduplicateSameParams642=== PAUSE TestGCTaskStore_DeduplicateSameParams643=== RUN TestGCTaskStore_ConflictDifferentParams644=== PAUSE TestGCTaskStore_ConflictDifferentParams645=== RUN TestGCTaskStore_GetEmpty646=== PAUSE TestGCTaskStore_GetEmpty647=== RUN TestGCTaskStore_GetReturnsLatest648=== PAUSE TestGCTaskStore_GetReturnsLatest649=== RUN TestGCTaskStore_CompletedAllowsNewTask650=== PAUSE TestGCTaskStore_CompletedAllowsNewTask651=== RUN TestGCTaskStore_PhaseUpdates652=== PAUSE TestGCTaskStore_PhaseUpdates653=== RUN TestGCTaskStore_Fail654=== PAUSE TestGCTaskStore_Fail655=== RUN TestGracefulShutdownDrainsInflight656=== PAUSE TestGracefulShutdownDrainsInflight657=== RUN TestService_healthCheckHandler658=== PAUSE TestService_healthCheckHandler659=== RUN TestService_readinessHandler660=== PAUSE TestService_readinessHandler661=== RUN TestGenerateLandingPage662=== PAUSE TestGenerateLandingPage663=== RUN TestCacheConfigHandlerMaxNarSize664=== PAUSE TestCacheConfigHandlerMaxNarSize665=== RUN TestCreatePendingClosureRejectsOversizedNAR666=== PAUSE TestCreatePendingClosureRejectsOversizedNAR667=== RUN TestNARDeduplicationMetadataUploadBug668=== PAUSE TestNARDeduplicationMetadataUploadBug669=== RUN TestMetricsInventory670=== PAUSE TestMetricsInventory671=== RUN TestService_NativeMTLS672=== PAUSE TestService_NativeMTLS673=== RUN TestServerTLSConfig674=== PAUSE TestServerTLSConfig675=== RUN TestMultipartCleanup676=== PAUSE TestMultipartCleanup677=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded678=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded679=== RUN TestPendingCleanupUsesOneCutoff680=== PAUSE TestPendingCleanupUsesOneCutoff681=== RUN TestPendingClosureFailureTracksEveryUpload682=== PAUSE TestPendingClosureFailureTracksEveryUpload683=== RUN TestPendingClosureFailureAbortsItsUploads684=== PAUSE TestPendingClosureFailureAbortsItsUploads685=== RUN TestObjectStatsTrigger686=== PAUSE TestObjectStatsTrigger687=== RUN TestReconnectLeavesObjectsUnlocked688=== PAUSE TestReconnectLeavesObjectsUnlocked689=== RUN TestOrphanedObjectsGC690=== PAUSE TestOrphanedObjectsGC691=== RUN TestOrphanedObjectsGCStressTest692=== PAUSE TestOrphanedObjectsGCStressTest693=== RUN TestCreatePin_ReservedPins694=== PAUSE TestCreatePin_ReservedPins695=== RUN TestConcurrentPinUpdatesAgree696=== PAUSE TestConcurrentPinUpdatesAgree697=== RUN TestCreatePinRejectsBadInput698=== PAUSE TestCreatePinRejectsBadInput699=== RUN TestDeletePinKeepsRowWhenS3Fails700=== PAUSE TestDeletePinKeepsRowWhenS3Fails701=== RUN TestPresentReportsOnlyClosureRoots702=== PAUSE TestPresentReportsOnlyClosureRoots703=== RUN TestPresentNotReportedWhileGCDeletesClosure704=== PAUSE TestPresentNotReportedWhileGCDeletesClosure705=== RUN TestParseSingleRange706=== PAUSE TestParseSingleRange707=== RUN TestProxyHeadersOnlyTrustedOnSocket708=== PAUSE TestProxyHeadersOnlyTrustedOnSocket709=== RUN TestIsValidCachePath710=== PAUSE TestIsValidCachePath711=== RUN TestReadProxyNarinfo712=== PAUSE TestReadProxyNarinfo713=== RUN TestReadProxyNarinfoAlreadyDecompressed714=== PAUSE TestReadProxyNarinfoAlreadyDecompressed715=== RUN TestReadProxyNarStreaming716=== PAUSE TestReadProxyNarStreaming717=== RUN TestReadProxy404718=== PAUSE TestReadProxy404719=== RUN TestReadProxyInvalidPath720=== PAUSE TestReadProxyInvalidPath721=== RUN TestReadProxyHead722=== PAUSE TestReadProxyHead723=== RUN TestReadProxyOutlastsServerWriteTimeout724=== PAUSE TestReadProxyOutlastsServerWriteTimeout725=== RUN TestReadProxyConditionalGet726=== PAUSE TestReadProxyConditionalGet727=== RUN TestReadProxyRootRedirectsToIndexHTML728=== PAUSE TestReadProxyRootRedirectsToIndexHTML729=== RUN TestReadProxyDisabled730=== PAUSE TestReadProxyDisabled731=== RUN TestReadRedirectNar732=== PAUSE TestReadRedirectNar733=== RUN TestReadRedirectKeepsNarinfoProxied734=== PAUSE TestReadRedirectKeepsNarinfoProxied735=== RUN TestReadProxyRangeRequest736=== PAUSE TestReadProxyRangeRequest737=== RUN TestReadRedirectUsesPublicS3URL738=== PAUSE TestReadRedirectUsesPublicS3URL739=== RUN TestPush_OverlappingRootsStoreOneRowPerKey740=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey741=== RUN TestPush_CompleteCommitsEveryRoot742=== PAUSE TestPush_CompleteCommitsEveryRoot743=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit744=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit745=== RUN TestPush_RejectsBadRequests746=== PAUSE TestPush_RejectsBadRequests747=== RUN TestPush_SignsNarinfosOfItsPendingObjects748=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects749=== RUN TestRedundantMultipartUpload750=== PAUSE TestRedundantMultipartUpload751=== RUN TestCompleteMultipartUpload_ErrorButObjectExists752=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists753=== RUN TestCompletedNarNotReofferedAcrossClosures754=== PAUSE TestCompletedNarNotReofferedAcrossClosures755=== RUN TestPresignedUploadRegisteredBeforeCommit756=== PAUSE TestPresignedUploadRegisteredBeforeCommit757=== RUN TestService_Rustfstest758=== PAUSE TestService_Rustfstest759=== RUN TestParseSize760=== PAUSE TestParseSize761=== RUN TestSkippedUploadsHandler762=== PAUSE TestSkippedUploadsHandler763=== RUN TestSystemdListenerNotActivated764--- PASS: TestSystemdListenerNotActivated (0.00s)765=== RUN TestWatchdogBeatsWhenHealthy766--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)767=== RUN TestWatchdogSkipsWhenUnhealthy7682026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/05 12:09:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"778--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)779=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== RUN TestProxyWriteTimeout782=== PAUSE TestProxyWriteTimeout783=== RUN TestPendingClosureWriteTimeout784=== PAUSE TestPendingClosureWriteTimeout785=== RUN TestIsValidUploadKey786=== PAUSE TestIsValidUploadKey787=== RUN TestUploadHandlersRejectInvalidKeys788=== PAUSE TestUploadHandlersRejectInvalidKeys789=== RUN TestUploadHandlersRejectOversizedBody790=== PAUSE TestUploadHandlersRejectOversizedBody791=== RUN TestService_cleanupPendingClosuresHandler792=== PAUSE TestService_cleanupPendingClosuresHandler793=== RUN TestService_createPendingClosureHandler794=== PAUSE TestService_createPendingClosureHandler795=== RUN TestService_verifyS3Integrity796=== PAUSE TestService_verifyS3Integrity797=== RUN TestCompleteMultipartUnregistered798=== PAUSE TestCompleteMultipartUnregistered799=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT800=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT801=== CONT TestSkippedUploadsHandler802=== CONT TestPush_SignsNarinfosOfItsPendingObjects803=== CONT TestPendingCleanupUsesOneCutoff804=== CONT TestConnectSerialisesConcurrentMigrations805=== CONT TestGCSweepDeliversEachKeyOnce806=== CONT TestGCSweepSkipsPendingObjects807=== CONT TestPendingClosureFailureAbortsItsUploads808=== CONT TestPushDedupSurvivesConcurrentGC809=== CONT TestService_AuthMiddleware_MTLSProxyHeader810=== CONT TestDeduplicatedObjectsRecordedAsPending811=== CONT TestPresignedUploadRegisteredBeforeCommit812=== CONT TestGCMetrics813=== CONT TestTombstonedObjectOfferedWithoutWaiting814=== CONT TestGCBugBareHashReferences815=== CONT TestLeadEndsOnShutdown816=== CONT TestGCTaskStore_GetEmpty817=== CONT TestPendingClosureFailureTracksEveryUpload818--- PASS: TestGCTaskStore_GetEmpty (0.00s)819=== CONT TestClientFallsBackToClosures8202026/10/05 12:09:36 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000821=== CONT TestGCAdvisoryLockBlocksConcurrentRun822=== CONT TestCompleteMultipartUpload_ErrorButObjectExists823=== CONT TestMultipartCleanup824=== CONT TestResolveDBConnectionString825=== CONT TestRegisterCompletedObjectNeedsPendingRow826=== CONT TestMetricsInventory827=== CONT TestGCTaskStore_ConflictDifferentParams828--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)829=== RUN TestResolveDBConnectionString/flag_wins830=== PAUSE TestResolveDBConnectionString/flag_wins831=== CONT TestReadProxyNarinfoAlreadyDecompressed832=== RUN TestResolveDBConnectionString/file_when_flag_empty833=== PAUSE TestResolveDBConnectionString/file_when_flag_empty834=== RUN TestResolveDBConnectionString/missing_file_is_an_error835=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error836=== RUN TestResolveDBConnectionString/PGHOST_allows_empty837=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty838=== RUN TestResolveDBConnectionString/nothing_configured839=== PAUSE TestResolveDBConnectionString/nothing_configured840=== CONT TestCreatePendingClosureRejectsOversizedNAR8412026/10/05 12:09:36 INFO Received uploads request method=POST path=/api/pending_closures842--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)843=== CONT TestConnectWaitsForAPeerMigration844--- PASS: TestSkippedUploadsHandler (0.04s)845=== CONT TestService_healthCheckHandler8462026-10-05 12:09:36.962 UTC [511] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"8472026-10-05 12:09:36.962 UTC [511] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.8482026-10-05 12:09:36.962 UTC [511] STATEMENT: CREATE TABLE goose_db_version (849 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,850 version_id bigint NOT NULL,851 is_applied boolean NOT NULL,852 tstamp timestamp NOT NULL DEFAULT now()853 )8542026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8552026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8562026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes857--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.39s)858=== CONT TestClientPushesUseOnePush8592026/10/05 12:09:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8602026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8612026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/05 12:09:37 INFO Signed narinfos id=1 count=18632026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures864=== CONT TestGCTaskStore_DeduplicateSameParams865--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.44s)866=== CONT TestPush_CompleteCommitsEveryRoot867--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)868--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.44s)869=== CONT TestGCTaskStore_StartNew870=== CONT TestForceGCDuringPushOffersSweptObject871=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows872--- PASS: TestGCTaskStore_StartNew (0.00s)873=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows874=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check875=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check876=== CONT TestGenerateLandingPage877=== CONT TestReadProxyInvalidPath878--- PASS: TestGenerateLandingPage (0.01s)8792026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8802026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=08812026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period8822026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08832026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8842026/10/05 12:09:37 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8852026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/05 12:09:37 INFO Vacuumed table table=pending_closures8872026/10/05 12:09:37 INFO Vacuumed table table=pending_objects8882026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads8892026/10/05 12:09:37 INFO Vacuumed table table=closures8902026/10/05 12:09:37 INFO Vacuumed table table=objects891--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.50s)892=== CONT TestPinProtectsFromGC893--- PASS: TestGCSweepSkipsPendingObjects (0.51s)894=== CONT TestIsValidCachePath895=== RUN TestIsValidCachePath/narinfo896=== PAUSE TestIsValidCachePath/narinfo897=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars898=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars899=== RUN TestIsValidCachePath/nar_zst900=== PAUSE TestIsValidCachePath/nar_zst901=== RUN TestIsValidCachePath/nar_xz902=== PAUSE TestIsValidCachePath/nar_xz903=== RUN TestIsValidCachePath/nar_bz2904=== PAUSE TestIsValidCachePath/nar_bz2905=== RUN TestIsValidCachePath/nar_uncompressed906=== PAUSE TestIsValidCachePath/nar_uncompressed907=== RUN TestIsValidCachePath/ls908=== PAUSE TestIsValidCachePath/ls909=== RUN TestIsValidCachePath/log910=== PAUSE TestIsValidCachePath/log911=== RUN TestIsValidCachePath/realisation912=== PAUSE TestIsValidCachePath/realisation913=== RUN TestIsValidCachePath/nix-cache-info914=== PAUSE TestIsValidCachePath/nix-cache-info915=== RUN TestIsValidCachePath/index.html916=== PAUSE TestIsValidCachePath/index.html917=== RUN TestIsValidCachePath/traversal_parent918=== PAUSE TestIsValidCachePath/traversal_parent919=== RUN TestIsValidCachePath/traversal_in_middle920=== PAUSE TestIsValidCachePath/traversal_in_middle921=== RUN TestIsValidCachePath/invalid_char_e922=== PAUSE TestIsValidCachePath/invalid_char_e923=== RUN TestIsValidCachePath/invalid_char_u924=== PAUSE TestIsValidCachePath/invalid_char_u925=== RUN TestIsValidCachePath/random_path926=== PAUSE TestIsValidCachePath/random_path927=== RUN TestIsValidCachePath/empty928=== PAUSE TestIsValidCachePath/empty929=== RUN TestIsValidCachePath/leading_slash930=== PAUSE TestIsValidCachePath/leading_slash931=== RUN TestIsValidCachePath/wrong_extension932=== PAUSE TestIsValidCachePath/wrong_extension933=== RUN TestIsValidCachePath/short_hash934=== PAUSE TestIsValidCachePath/short_hash935=== CONT TestPresentNotReportedWhileGCDeletesClosure9362026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures937=== CONT TestReadProxy404938--- PASS: TestPendingClosureFailureAbortsItsUploads (0.52s)9392026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=09412026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period942=== CONT TestProxyWriteTimeout943--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.57s)944=== RUN TestProxyWriteTimeout/narinfo945=== PAUSE TestProxyWriteTimeout/narinfo946=== RUN TestProxyWriteTimeout/1_GiB_nar947=== PAUSE TestProxyWriteTimeout/1_GiB_nar948=== RUN TestProxyWriteTimeout/10_GiB_nar949=== PAUSE TestProxyWriteTimeout/10_GiB_nar950=== RUN TestProxyWriteTimeout/unknown_size951=== PAUSE TestProxyWriteTimeout/unknown_size952=== CONT TestService_ReadAuthMiddleware9532026/10/05 12:09:37 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=09542026/10/05 12:09:37 INFO Vacuumed table table=pending_closures9552026/10/05 12:09:37 INFO Vacuumed table table=pending_objects9562026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads9572026/10/05 12:09:37 INFO Vacuumed table table=closures9582026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/05 12:09:37 INFO Vacuumed table table=objects9602026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=0961--- PASS: TestGCSweepDeliversEachKeyOnce (0.60s)9622026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0963=== CONT TestIsValidUploadKey964=== RUN TestIsValidUploadKey/narinfo965=== PAUSE TestIsValidUploadKey/narinfo966=== RUN TestIsValidUploadKey/nar_zst967=== PAUSE TestIsValidUploadKey/nar_zst968=== RUN TestIsValidUploadKey/nar_xz969=== PAUSE TestIsValidUploadKey/nar_xz970=== RUN TestIsValidUploadKey/nar_plain971=== PAUSE TestIsValidUploadKey/nar_plain972=== RUN TestIsValidUploadKey/listing973=== PAUSE TestIsValidUploadKey/listing974=== RUN TestIsValidUploadKey/build_log975=== PAUSE TestIsValidUploadKey/build_log976=== RUN TestIsValidUploadKey/build_log_home-manager_file977=== PAUSE TestIsValidUploadKey/build_log_home-manager_file978=== RUN TestIsValidUploadKey/build_log_plus_in_name979=== PAUSE TestIsValidUploadKey/build_log_plus_in_name980=== RUN TestIsValidUploadKey/build_log_question_mark981=== PAUSE TestIsValidUploadKey/build_log_question_mark982=== RUN TestIsValidUploadKey/build_log_equals983=== PAUSE TestIsValidUploadKey/build_log_equals984=== RUN TestIsValidUploadKey/realisation985=== PAUSE TestIsValidUploadKey/realisation9862026/10/05 12:09:37 INFO Vacuumed table table=pending_closures987=== RUN TestIsValidUploadKey/realisation_plus_in_output988=== PAUSE TestIsValidUploadKey/realisation_plus_in_output989=== RUN TestIsValidUploadKey/nix-cache-info990=== PAUSE TestIsValidUploadKey/nix-cache-info991=== RUN TestIsValidUploadKey/index.html992=== PAUSE TestIsValidUploadKey/index.html993=== RUN TestIsValidUploadKey/narinfo_key,_nar_type994=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type995=== RUN TestIsValidUploadKey/nar_key,_narinfo_type996=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type997=== RUN TestIsValidUploadKey/listing_key,_narinfo_type998=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type999=== RUN TestIsValidUploadKey/traversal1000=== PAUSE TestIsValidUploadKey/traversal1001=== RUN TestIsValidUploadKey/traversal_nar1002=== PAUSE TestIsValidUploadKey/traversal_nar1003=== RUN TestIsValidUploadKey/absolute1004=== PAUSE TestIsValidUploadKey/absolute1005=== RUN TestIsValidUploadKey/empty_key1006=== PAUSE TestIsValidUploadKey/empty_key1007=== RUN TestIsValidUploadKey/unknown_type1008=== PAUSE TestIsValidUploadKey/unknown_type1009=== CONT TestService_AuthMiddleware10102026/10/05 12:09:37 INFO Vacuumed table table=pending_objects10112026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads10122026/10/05 12:09:37 INFO Vacuumed table table=closures10132026/10/05 12:09:37 INFO Vacuumed table table=objects10142026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=010152026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period10162026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010172026/10/05 12:09:37 INFO Vacuumed table table=pending_closures10182026/10/05 12:09:37 INFO Vacuumed table table=pending_objects10192026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads10202026/10/05 12:09:37 INFO Vacuumed table table=closures10212026/10/05 12:09:37 INFO Vacuumed table table=objects1022--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.63s)1023=== CONT TestService_RequireScope_OIDC10242026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1025--- PASS: TestPushDedupSurvivesConcurrentGC (0.65s)1026=== CONT TestService_createPendingClosureHandler1027=== CONT TestService_cleanupPendingClosuresHandler1028--- PASS: TestMetricsInventory (0.68s)10292026/10/05 12:09:37 INFO lead: acquired remote=192.0.2.1:123410302026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1031=== CONT TestUploadHandlersRejectInvalidKeys1032--- PASS: TestService_healthCheckHandler (0.72s)1033=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1034=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1035=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1036=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1037=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1038=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1039=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1040=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1041=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10422026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=010432026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period10442026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010452026/10/05 12:09:37 INFO Vacuumed table table=pending_closures10462026/10/05 12:09:37 INFO Vacuumed table table=pending_objects10472026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads10482026/10/05 12:09:37 INFO Vacuumed table table=closures10492026/10/05 12:09:37 INFO Vacuumed table table=objects10502026/10/05 12:09:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10512026/10/05 12:09:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10522026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=110532026/10/05 12:09:37 INFO Received cleanup request method=DELETE path=/api/pending_closures10542026/10/05 12:09:37 INFO Aborted multipart uploads count=1 kept=01055--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.78s)1056=== CONT TestLeadElectsOneAndHandsOver1057=== CONT TestPushWaitsForSweepHoldingRow1058--- PASS: TestMultipartCleanup (0.80s)1059=== CONT TestGCTaskStore_CompletedAllowsNewTask1060=== CONT TestSweepRechecksPendingAfterLocking1061--- PASS: TestGCMetrics (0.82s)1062--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)10632026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes10642026/10/05 12:09:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38265/oidc10652026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1066--- PASS: TestReadProxyInvalidPath (0.41s)1067=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10682026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures10692026/10/05 12:09:37 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10702026/10/05 12:09:37 INFO Uploading pv0cxv8jrzgc1zixwgr7hwl21mlp4nkk-b (216B)10712026/10/05 12:09:37 INFO Uploading 1fszc49jn8vj9s93dvxn6zlhdda8pczq-shared-dep (136B)10722026/10/05 12:09:37 WARN Failed to register uploaded object key=80al5fg6b8h0fykqhyvkqnxprzkxll83.ls error="server returned 404: 404 page not found\n"10732026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10742026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/1bqncz9r2f0s2idwb60fkgpkh3702g3vhdxfxh493hcq2l2y09zx.nar.zst error="server returned 404: 404 page not found\n"10752026/10/05 12:09:37 WARN Failed to register uploaded object key=1fszc49jn8vj9s93dvxn6zlhdda8pczq.ls error="server returned 404: 404 page not found\n"10762026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10772026/10/05 12:09:37 WARN Failed to register uploaded object key=pv0cxv8jrzgc1zixwgr7hwl21mlp4nkk.ls error="server returned 404: 404 page not found\n"10782026/10/05 12:09:37 INFO Signed narinfos id=1 count=210792026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10802026/10/05 12:09:37 INFO Signed narinfos id=2 count=210812026/10/05 12:09:37 INFO Uploading 4 narinfos10822026/10/05 12:09:37 WARN Failed to register uploaded object key=80al5fg6b8h0fykqhyvkqnxprzkxll83.narinfo error="server returned 404: 404 page not found\n"10832026/10/05 12:09:37 WARN Failed to register uploaded object key=1fszc49jn8vj9s93dvxn6zlhdda8pczq.narinfo error="server returned 404: 404 page not found\n"10842026/10/05 12:09:37 WARN Failed to register uploaded object key=pv0cxv8jrzgc1zixwgr7hwl21mlp4nkk.narinfo error="server returned 404: 404 page not found\n"10852026/10/05 12:09:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10862026/10/05 12:09:37 WARN Failed to register uploaded object key=1fszc49jn8vj9s93dvxn6zlhdda8pczq.narinfo error="server returned 404: 404 page not found\n"10872026/10/05 12:09:37 INFO Completed upload id=110882026/10/05 12:09:37 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10892026/10/05 12:09:37 INFO Completed upload id=210902026/10/05 12:09:37 INFO Upload complete. (100ms)1091=== NAME TestClientFallsBackToClosures1092 client_pushes_test.go:112: Retrieved narinfo from S3:1093 StorePath: /build/TestClientFallsBackToClosures3421001513/001/store/1fszc49jn8vj9s93dvxn6zlhdda8pczq-shared-dep1094 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1095 Compression: zstd1096 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821097 NarSize: 1361098 References: 1099 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1100 client_pushes_test.go:112: Retrieved narinfo from S3:1101 StorePath: /build/TestClientFallsBackToClosures3421001513/001/store/80al5fg6b8h0fykqhyvkqnxprzkxll83-a1102 URL: nar/1bqncz9r2f0s2idwb60fkgpkh3702g3vhdxfxh493hcq2l2y09zx.nar.zst1103 Compression: zstd1104 NarHash: sha256:1bqncz9r2f0s2idwb60fkgpkh3702g3vhdxfxh493hcq2l2y09zx1105 NarSize: 2161106 References: /build/TestClientFallsBackToClosures3421001513/001/store/1fszc49jn8vj9s93dvxn6zlhdda8pczq-shared-dep1107 CA: text:sha256:1cg6zg3x7ynpd66gkcakajayvsn1kz89gr4akjm2ak4vypvn6r2f11082026/10/05 12:09:37 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1109 client_pushes_test.go:112: Retrieved narinfo from S3:1110 StorePath: /build/TestClientFallsBackToClosures3421001513/001/store/pv0cxv8jrzgc1zixwgr7hwl21mlp4nkk-b1111 URL: nar/1bqncz9r2f0s2idwb60fkgpkh3702g3vhdxfxh493hcq2l2y09zx.nar.zst1112 Compression: zstd1113 NarHash: sha256:1bqncz9r2f0s2idwb60fkgpkh3702g3vhdxfxh493hcq2l2y09zx1114 NarSize: 2161115 References: /build/TestClientFallsBackToClosures3421001513/001/store/1fszc49jn8vj9s93dvxn6zlhdda8pczq-shared-dep1116 CA: text:sha256:1cg6zg3x7ynpd66gkcakajayvsn1kz89gr4akjm2ak4vypvn6r2f1117=== NAME TestPinProtectsFromGC1118 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1488729013/001/store/dy0n2by65361vn7c4cackqgr8wyjbr9z-pinned-file.txt1119 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1488729013/001/store/i64x2b46fh19jjags77swdsgdx0w73p6-unpinned-file.txt1120--- PASS: TestClientFallsBackToClosures (0.96s)1121=== CONT TestService_Rustfstest1122--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.96s)1123=== CONT TestParseSize1124=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1125=== CONT TestLeadIncumbentAnnouncesAtOnce1126--- PASS: TestService_ReadAuthMiddleware (0.40s)1127--- PASS: TestParseSize (0.00s)11282026/10/05 12:09:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11292026/10/05 12:09:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"11302026/10/05 12:09:37 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjM4ZTYwNzBjLTE5ZDQtNDE5My1iYTJmLTdlOTVkN2UyNjZkZHgxNzkxMjAyMTc3NDMyNTU3Mjg51131--- PASS: TestService_AuthMiddleware (0.38s)1132=== CONT TestRedundantMultipartUpload11332026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures11342026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures11352026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures11362026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes11372026/10/05 12:09:37 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11382026/10/05 12:09:37 INFO Uploading yvcqwvsm7cmm99zyskgrlgcwq3j8klr6-b (216B)11392026/10/05 12:09:37 INFO Uploading 7qki91ga05yvpyh0nmn398cp0k7w58kg-shared-dep (136B)11402026/10/05 12:09:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11412026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=011422026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures11432026/10/05 12:09:37 WARN Failed to register uploaded object key=37b855ycx7hvwv2ccyn5h2gkf09f4jyn.ls error="server returned 404: 404 page not found\n"11442026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/0cdc568cp4f97iykmd3s8y9avc078g5q458zvjpkqp80hd9avw0b.nar.zst error="server returned 404: 404 page not found\n"11452026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11462026/10/05 12:09:37 WARN Failed to register uploaded object key=7qki91ga05yvpyh0nmn398cp0k7w58kg.ls error="server returned 404: 404 page not found\n"11472026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11482026/10/05 12:09:37 WARN Failed to register uploaded object key=yvcqwvsm7cmm99zyskgrlgcwq3j8klr6.ls error="server returned 404: 404 page not found\n"11492026/10/05 12:09:37 INFO Signed narinfos id=1 count=311502026/10/05 12:09:37 INFO Uploading 3 narinfos11512026/10/05 12:09:37 WARN Failed to register uploaded object key=37b855ycx7hvwv2ccyn5h2gkf09f4jyn.narinfo error="server returned 404: 404 page not found\n"11522026/10/05 12:09:37 WARN Failed to register uploaded object key=7qki91ga05yvpyh0nmn398cp0k7w58kg.narinfo error="server returned 404: 404 page not found\n"11532026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/1/complete11542026/10/05 12:09:37 WARN Failed to register uploaded object key=yvcqwvsm7cmm99zyskgrlgcwq3j8klr6.narinfo error="server returned 404: 404 page not found\n"11552026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes11562026/10/05 12:09:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11572026/10/05 12:09:37 INFO Upload complete. (86ms)11582026/10/05 12:09:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11592026/10/05 12:09:37 INFO Uploading dy0n2by65361vn7c4cackqgr8wyjbr9z-pinned-file.txt (128B)11602026/10/05 12:09:37 INFO Aborted multipart uploads count=1 kept=01161=== NAME TestClientPushesUseOnePush1162 client_pushes_test.go:97: Retrieved narinfo from S3:1163 StorePath: /build/TestClientPushesUseOnePush2635956021/001/store/7qki91ga05yvpyh0nmn398cp0k7w58kg-shared-dep1164 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1165 Compression: zstd1166 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821167 NarSize: 1361168 References: 1169 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11702026/10/05 12:09:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11712026-10-05 12:09:37.755 UTC [614] ERROR: Closure does not exist: id=111722026-10-05 12:09:37.755 UTC [614] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11732026-10-05 12:09:37.755 UTC [614] STATEMENT: -- name: CommitPendingClosure :exec1174 SELECT commit_pending_closure($1::bigint)1175 1176 client_pushes_test.go:97: Retrieved narinfo from S3:1177 StorePath: /build/TestClientPushesUseOnePush2635956021/001/store/37b855ycx7hvwv2ccyn5h2gkf09f4jyn-a1178 URL: nar/0cdc568cp4f97iykmd3s8y9avc078g5q458zvjpkqp80hd9avw0b.nar.zst1179 Compression: zstd1180 NarHash: sha256:0cdc568cp4f97iykmd3s8y9avc078g5q458zvjpkqp80hd9avw0b1181 NarSize: 2161182 References: /build/TestClientPushesUseOnePush2635956021/001/store/7qki91ga05yvpyh0nmn398cp0k7w58kg-shared-dep1183 CA: text:sha256:1n9h9yajx4jfda7ydl101my33mqg091lsg57as6dadkmlxm0hfa311842026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1185--- PASS: TestGCBugBareHashReferences (1.04s)1186=== CONT TestServerTLSConfig1187=== RUN TestServerTLSConfig/no_client_CA1188=== PAUSE TestServerTLSConfig/no_client_CA1189=== RUN TestServerTLSConfig/missing_CA_file1190=== PAUSE TestServerTLSConfig/missing_CA_file1191=== RUN TestServerTLSConfig/not_a_PEM_file1192=== PAUSE TestServerTLSConfig/not_a_PEM_file1193=== CONT TestCompletedNarNotReofferedAcrossClosures11942026/10/05 12:09:37 INFO lead: acquired remote=192.0.2.1:123411952026/10/05 12:09:37 WARN Failed to register uploaded object key=dy0n2by65361vn7c4cackqgr8wyjbr9z.ls error="server returned 404: 404 page not found\n"11962026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11972026/10/05 12:09:37 INFO Signed narinfos id=1 count=111982026/10/05 12:09:37 INFO Uploading 1 narinfos1199=== NAME TestClientPushesUseOnePush1200 client_pushes_test.go:97: Retrieved narinfo from S3:1201 StorePath: /build/TestClientPushesUseOnePush2635956021/001/store/yvcqwvsm7cmm99zyskgrlgcwq3j8klr6-b1202 URL: nar/0cdc568cp4f97iykmd3s8y9avc078g5q458zvjpkqp80hd9avw0b.nar.zst1203 Compression: zstd1204 NarHash: sha256:0cdc568cp4f97iykmd3s8y9avc078g5q458zvjpkqp80hd9avw0b1205 NarSize: 2161206 References: /build/TestClientPushesUseOnePush2635956021/001/store/7qki91ga05yvpyh0nmn398cp0k7w58kg-shared-dep1207 CA: text:sha256:1n9h9yajx4jfda7ydl101my33mqg091lsg57as6dadkmlxm0hfa31208--- PASS: TestService_cleanupPendingClosuresHandler (0.37s)1209=== CONT TestService_NativeMTLS12102026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12112026/10/05 12:09:37 WARN Failed to register uploaded object key=dy0n2by65361vn7c4cackqgr8wyjbr9z.narinfo error="server returned 404: 404 page not found\n"12122026/10/05 12:09:37 INFO Upload complete. (79ms)12132026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1214--- PASS: TestClientPushesUseOnePush (0.69s)1215=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12162026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=012172026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period1218--- PASS: TestPendingClosureFailureTracksEveryUpload (1.12s)1219=== CONT TestSweepSkipsRowsLockedByPush12202026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012212026/10/05 12:09:37 INFO Vacuumed table table=pending_closures12222026/10/05 12:09:37 INFO Vacuumed table table=pending_objects12232026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads12242026/10/05 12:09:37 INFO Vacuumed table table=closures12252026/10/05 12:09:37 INFO Vacuumed table table=objects12262026/10/05 12:09:37 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjM4ZTYwNzBjLTE5ZDQtNDE5My1iYTJmLTdlOTVkN2UyNjZkZHgxNzkxMjAyMTc3NDMyNTU3Mjg5 error="Delete \"http://localhost:46339/bucket20/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjM4ZTYwNzBjLTE5ZDQtNDE5My1iYTJmLTdlOTVkN2UyNjZkZHgxNzkxMjAyMTc3NDMyNTU3Mjg5\": injected: abort refused"12272026/10/05 12:09:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12282026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1229=== RUN TestService_RequireScope_OIDC/builder_may_write1230=== PAUSE TestService_RequireScope_OIDC/builder_may_write1231=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1232=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1233=== RUN TestService_RequireScope_OIDC/ops_may_admin1234=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1235=== RUN TestService_RequireScope_OIDC/ops_may_not_write1236=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1237=== RUN TestService_RequireScope_OIDC/reader_may_not_write1238=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1239=== RUN TestService_RequireScope_OIDC/static_token_may_admin1240=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1241=== RUN TestService_RequireScope_OIDC/static_token_may_write1242=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1243=== RUN TestService_RequireScope_OIDC/reader_may_read1244=== PAUSE TestService_RequireScope_OIDC/reader_may_read1245=== RUN TestService_RequireScope_OIDC/writer_implies_read1246=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1247=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1248=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1249=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1250=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1251=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1252=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1253=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1254=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1255=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1256=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1257=== CONT TestGracefulShutdownDrainsInflight12582026/10/05 12:09:37 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjM4ZTYwNzBjLTE5ZDQtNDE5My1iYTJmLTdlOTVkN2UyNjZkZHgxNzkxMjAyMTc3NDMyNTU3Mjg512592026/10/05 12:09:37 INFO Starting HTTP server address=127.0.0.1:3825112602026/10/05 12:09:37 INFO Shutdown signal received, draining in-flight requests timeout=10s12612026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes1262=== CONT TestGCTaskStore_GetReturnsLatest1263--- PASS: TestSweepRechecksPendingAfterLocking (0.33s)1264=== CONT TestPush_RejectsBadRequests1265--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)12662026/10/05 12:09:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12672026/10/05 12:09:37 INFO Uploading i64x2b46fh19jjags77swdsgdx0w73p6-unpinned-file.txt (128B)12682026/10/05 12:09:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjM4ZTYwNzBjLTE5ZDQtNDE5My1iYTJmLTdlOTVkN2UyNjZkZHgxNzkxMjAyMTc3NDMyNTU3Mjg5 parts=112692026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12702026/10/05 12:09:37 WARN Failed to register uploaded object key=i64x2b46fh19jjags77swdsgdx0w73p6.ls error="server returned 404: 404 page not found\n"12712026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12722026/10/05 12:09:37 INFO Signed narinfos id=2 count=112732026/10/05 12:09:37 INFO Uploading 1 narinfos12742026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/2/complete12752026/10/05 12:09:37 WARN Failed to register uploaded object key=i64x2b46fh19jjags77swdsgdx0w73p6.narinfo error="server returned 404: 404 page not found\n"12762026/10/05 12:09:37 INFO Upload complete. (68ms)1277--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.17s)1278=== CONT TestFailedS3DeleteKeepsTombstone1279=== CONT TestGCEndsOnShutdown1280--- PASS: TestService_Rustfstest (0.22s)1281=== RUN TestGCEndsOnShutdown/before_the_run1282=== PAUSE TestGCEndsOnShutdown/before_the_run1283=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1284=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1285=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1286=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1287=== CONT TestGCTaskStore_Fail1288=== CONT TestGetExistingObjectsLocksRows1289--- PASS: TestGCTaskStore_Fail (0.00s)12902026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures1291--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1292=== CONT TestGCTaskStore_PhaseUpdates1293--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1294=== CONT TestCacheConfigHandlerMaxNarSize1295--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1296=== CONT TestReadRedirectUsesPublicS3URL12972026/10/05 12:09:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures12982026/10/05 12:09:37 INFO Garbage collection started12992026/10/05 12:09:37 INFO lead: acquired remote=192.0.2.1:123413002026/10/05 12:09:37 INFO lead: released remote=192.0.2.1:123413012026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=013022026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period1303--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.29s)1304=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1305--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.29s)1306=== CONT TestCommitRacingPendingCleanupKeepsObjects13072026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/05 12:09:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13092026/10/05 12:09:37 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=01310=== CONT TestOrphanedObjectsGCStressTest1311--- PASS: TestConnectSerialisesConcurrentMigrations (1.27s)13122026/10/05 12:09:37 INFO Vacuumed table table=pending_closures13132026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures13142026/10/05 12:09:37 INFO Vacuumed table table=pending_objects13152026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads13162026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures13172026/10/05 12:09:38 INFO Vacuumed table table=closures13182026/10/05 12:09:38 INFO Vacuumed table table=objects13192026/10/05 12:09:38 WARN Rate limiter enabled after throttle name=s3-test rate=513202026/10/05 12:09:38 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."13212026/10/05 12:09:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13222026/10/05 12:09:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1323--- PASS: TestService_NativeMTLS (0.29s)1324=== CONT TestReadProxyOutlastsServerWriteTimeout13252026/10/05 12:09:38 WARN Rate limiter backed off name=s3-test rate=513262026/10/05 12:09:38 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1327=== CONT TestReadProxyConditionalGet1328--- PASS: TestReadProxy404 (0.88s)13292026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13302026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=01331--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.93s)1332=== CONT TestReadProxyHead13332026/10/05 12:09:38 WARN Force mode enabled - objects will be deleted immediately without grace period1334=== RUN TestPush_RejectsBadRequests/root_not_in_objects1335=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1336=== RUN TestPush_RejectsBadRequests/no_roots1337=== PAUSE TestPush_RejectsBadRequests/no_roots1338=== RUN TestPush_RejectsBadRequests/no_objects1339=== PAUSE TestPush_RejectsBadRequests/no_objects1340=== RUN TestPush_RejectsBadRequests/bad_root1341=== PAUSE TestPush_RejectsBadRequests/bad_root1342=== CONT TestCacheStatsHandler13432026/10/05 12:09:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013442026/10/05 12:09:38 INFO Vacuumed table table=pending_closures13452026/10/05 12:09:38 INFO Vacuumed table table=pending_objects13462026/10/05 12:09:38 INFO Vacuumed table table=multipart_uploads13472026/10/05 12:09:38 INFO Vacuumed table table=closures13482026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjJkNGFkOTlkLWUzNjktNDYwYS1hNWQ3LTMzODg5NWJmMDVhNngxNzkxMjAyMTc3NTQ4ODgyMDI4 parts=1013492026/10/05 12:09:38 INFO Vacuumed table table=objects13502026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=013512026/10/05 12:09:38 WARN Force mode enabled - objects will be deleted immediately without grace period13522026/10/05 12:09:38 INFO Received push request method=POST path=/api/pushes13532026/10/05 12:09:38 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=013542026/10/05 12:09:38 INFO Vacuumed table table=pending_closures13552026/10/05 12:09:38 INFO Vacuumed table table=pending_objects13562026/10/05 12:09:38 INFO Vacuumed table table=multipart_uploads13572026/10/05 12:09:38 INFO Vacuumed table table=closures13582026/10/05 12:09:38 INFO Vacuumed table table=objects1359--- PASS: TestSweepSkipsRowsLockedByPush (0.38s)1360=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13612026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures1362--- PASS: TestPushWaitsForSweepHoldingRow (0.80s)1363=== CONT TestClientSharedPathCommittedMidPush1364=== CONT TestService_readinessHandler1365--- PASS: TestGetExistingObjectsLocksRows (0.44s)13662026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures13672026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=013682026/10/05 12:09:38 WARN Force mode enabled - objects will be deleted immediately without grace period13692026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13702026/10/05 12:09:38 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13712026/10/05 12:09:38 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13722026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjRlOTdjODA2LTVkYWMtNDFhYi1iMWZhLWExMGQ3ZmU2MjE2M3gxNzkxMjAyMTc3NzEwMjUzMjg5 parts=1013732026/10/05 12:09:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13742026/10/05 12:09:38 INFO Completed upload id=113752026/10/05 12:09:38 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001376=== CONT TestReadProxyRangeRequest1377--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)13782026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures13792026/10/05 12:09:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures13802026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=013812026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=013822026/10/05 12:09:38 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=013832026/10/05 12:09:38 WARN Force mode enabled - objects will be deleted immediately without grace period13842026/10/05 12:09:38 INFO Vacuumed table table=pending_closures13852026/10/05 12:09:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013862026/10/05 12:09:38 INFO Vacuumed table table=pending_objects13872026/10/05 12:09:38 INFO Vacuumed table table=pending_closures13882026/10/05 12:09:38 INFO Vacuumed table table=multipart_uploads13892026/10/05 12:09:38 INFO Vacuumed table table=pending_objects13902026/10/05 12:09:38 INFO Vacuumed table table=multipart_uploads13912026/10/05 12:09:38 INFO Vacuumed table table=closures13922026/10/05 12:09:38 INFO Vacuumed table table=closures13932026/10/05 12:09:38 INFO Vacuumed table table=objects13942026/10/05 12:09:38 INFO Vacuumed table table=objects13952026/10/05 12:09:38 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013962026/10/05 12:09:38 INFO lead: released remote=192.0.2.1:12341397=== CONT TestReadRedirectKeepsNarinfoProxied1398--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.49s)1399--- PASS: TestService_createPendingClosureHandler (1.11s)1400=== CONT TestConcurrentPinUpdatesAgree1401--- PASS: TestLeadEndsOnShutdown (1.76s)1402=== CONT TestReadProxyDisabled14032026/10/05 12:09:38 INFO Received push request method=POST path=/api/pushes1404--- PASS: TestReadRedirectUsesPublicS3URL (0.59s)1405=== CONT TestCreatePin_ReservedPins1406=== CONT TestParseSingleRange1407=== RUN TestParseSingleRange/none1408--- PASS: TestCacheStatsHandler (0.36s)1409=== PAUSE TestParseSingleRange/none1410=== RUN TestParseSingleRange/unknown_unit1411=== PAUSE TestParseSingleRange/unknown_unit1412=== RUN TestParseSingleRange/multi-range_ignored1413=== PAUSE TestParseSingleRange/multi-range_ignored1414=== RUN TestParseSingleRange/malformed_no_dash1415=== PAUSE TestParseSingleRange/malformed_no_dash1416=== RUN TestParseSingleRange/malformed_both_empty1417=== PAUSE TestParseSingleRange/malformed_both_empty1418=== RUN TestParseSingleRange/malformed_end_before_start1419=== PAUSE TestParseSingleRange/malformed_end_before_start1420=== RUN TestParseSingleRange/closed1421=== PAUSE TestParseSingleRange/closed1422=== RUN TestParseSingleRange/open-ended1423=== PAUSE TestParseSingleRange/open-ended1424=== RUN TestParseSingleRange/end_clamped_to_size1425=== PAUSE TestParseSingleRange/end_clamped_to_size1426=== RUN TestParseSingleRange/suffix1427=== PAUSE TestParseSingleRange/suffix1428=== RUN TestParseSingleRange/suffix_exceeds_size1429=== PAUSE TestParseSingleRange/suffix_exceeds_size1430=== RUN TestParseSingleRange/single_byte1431=== PAUSE TestParseSingleRange/single_byte1432=== RUN TestParseSingleRange/start_past_EOF1433=== PAUSE TestParseSingleRange/start_past_EOF1434=== RUN TestParseSingleRange/start_far_past_EOF1435=== PAUSE TestParseSingleRange/start_far_past_EOF1436=== CONT TestService_ReadScope_PublicByDefault1437--- PASS: TestReadProxyConditionalGet (0.43s)1438=== CONT TestReadProxyNarinfo14392026/10/05 12:09:38 WARN readiness check failed error="closed pool"1440--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.36s)1441=== CONT TestReadRedirectNar1442--- PASS: TestReadProxyHead (0.42s)1443=== CONT TestClientMultipleUploads1444=== CONT TestReadProxyRootRedirectsToIndexHTML1445--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.61s)1446--- PASS: TestService_readinessHandler (0.25s)1447=== CONT TestReadProxyNarStreaming1448--- PASS: TestReadProxyRangeRequest (0.24s)1449=== CONT TestClientWithDependencies14502026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/app14512026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/app14522026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14532026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14542026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14552026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjQ4ZTYyMTNlLWUzODYtNGM3MC04ZGVlLTBjYjAwNzAxM2JjYXgxNzkxMjAyMTc3NTQ4ODkzODA4 parts=1014562026/10/05 12:09:38 INFO Received push request method=POST path=/api/pushes14572026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LmJkMDA0YzhlLWIyYzItNGE1OS1hNGQ2LTRlYjdhZTZkNGE1MXgxNzkxMjAyMTc3OTg0NDM4Njc3 parts=1214582026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures14592026/10/05 12:09:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14602026/10/05 12:09:38 INFO Uploading qmpbfk0vqccbr11z4r4vrpjvn3q7r7kq-top (224B)14612026/10/05 12:09:38 INFO Uploading 21j9b7gikmgapwiin1bvpjyyghif50i4-shared-dep (136B)14622026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2Ljc5ZWMwOTcyLWI4ZTktNDJmMC05NDEzLWRhNTExYTc0MTE4YngxNzkxMjAyMTc4MDA5NjI5ODgy parts=1214632026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures14642026/10/05 12:09:38 WARN Failed to register uploaded object key=nar/1pmpw25k2yi57f6ww2xy25j6iqd9iibcl7ka82xnvaxfpspxvc8h.nar.zst error="server returned 404: 404 page not found\n"14652026/10/05 12:09:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40437/oidc14662026/10/05 12:09:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14672026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures14682026/10/05 12:09:38 WARN Failed to register uploaded object key=qmpbfk0vqccbr11z4r4vrpjvn3q7r7kq.ls error="server returned 404: 404 page not found\n"14692026/10/05 12:09:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1470--- PASS: TestReadProxyDisabled (0.26s)1471=== CONT TestDeletePinKeepsRowWhenS3Fails14722026/10/05 12:09:38 INFO Signed narinfos id=1 count=214732026/10/05 12:09:38 INFO Uploading 2 narinfos14742026/10/05 12:09:38 WARN Failed to register uploaded object key=21j9b7gikmgapwiin1bvpjyyghif50i4.ls error="server returned 404: 404 page not found\n"14752026/10/05 12:09:38 WARN Failed to register uploaded object key=qmpbfk0vqccbr11z4r4vrpjvn3q7r7kq.narinfo error="server returned 404: 404 page not found\n"14762026/10/05 12:09:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14772026/10/05 12:09:38 WARN Failed to register uploaded object key=21j9b7gikmgapwiin1bvpjyyghif50i4.narinfo error="server returned 404: 404 page not found\n"14782026/10/05 12:09:38 INFO Upload complete. (91ms)1479=== CONT TestCreatePinRejectsBadInput1480--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.00s)1481--- PASS: TestService_ReadScope_PublicByDefault (0.24s)1482=== CONT TestNARDeduplicationMetadataUploadBug1483=== NAME TestClientSharedPathCommittedMidPush1484 client_integration_test.go:816: Retrieved narinfo from S3:1485 StorePath: /build/TestClientSharedPathCommittedMidPush2008954299/001/store/21j9b7gikmgapwiin1bvpjyyghif50i4-shared-dep1486 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1487 Compression: zstd1488 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821489 NarSize: 1361490 References: 1491 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1492 client_integration_test.go:816: Retrieved narinfo from S3:1493 StorePath: /build/TestClientSharedPathCommittedMidPush2008954299/001/store/qmpbfk0vqccbr11z4r4vrpjvn3q7r7kq-top1494 URL: nar/1pmpw25k2yi57f6ww2xy25j6iqd9iibcl7ka82xnvaxfpspxvc8h.nar.zst1495 Compression: zstd1496 NarHash: sha256:1pmpw25k2yi57f6ww2xy25j6iqd9iibcl7ka82xnvaxfpspxvc8h1497 NarSize: 2241498 References: /build/TestClientSharedPathCommittedMidPush2008954299/001/store/21j9b7gikmgapwiin1bvpjyyghif50i4-shared-dep1499 CA: text:sha256:1c9pypy7h8n0l0fq2641k0ivhljm6s7gav1a7ivadm2afznaj1nz15002026/10/05 12:09:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1501--- PASS: TestClientSharedPathCommittedMidPush (0.49s)1502=== CONT TestObjectStatsTrigger15032026/10/05 12:09:38 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2Ljc5NDIyMDkxLTJiMmMtNDhjZi04Y2EyLTFmODRkNGE5NGUxMHgxNzkxMjAyMTc4MTkzODk5NzQ3 parts=101504=== NAME TestClientMultipleUploads1505 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads1282812433/001/store/adp5vsp9g1734piy2rapza420rk1bvq6-test-file-0.txt1506=== CONT TestClientErrorHandling1507--- PASS: TestReadRedirectKeepsNarinfoProxied (0.37s)1508=== RUN TestClientErrorHandling/InvalidStorePath1509=== PAUSE TestClientErrorHandling/InvalidStorePath1510=== RUN TestClientErrorHandling/InvalidAuthToken1511=== PAUSE TestClientErrorHandling/InvalidAuthToken1512=== RUN TestClientErrorHandling/ServerNotAvailable1513=== PAUSE TestClientErrorHandling/ServerNotAvailable1514=== CONT TestOrphanedObjectsGC1515--- PASS: TestReadRedirectNar (0.28s)1516=== CONT TestReconnectLeavesObjectsUnlocked1517=== NAME TestClientMultipleUploads1518 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads1282812433/001/store/gcp6wnk1mzrf8y1x35xcnqpa2cw2d93r-test-file-1.txt1519--- PASS: TestReadProxyNarStreaming (0.30s)1520=== CONT TestPresentReportsOnlyClosureRoots1521=== CONT TestProxyHeadersOnlyTrustedOnSocket1522--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.31s)1523=== NAME TestClientMultipleUploads1524 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads1282812433/001/store/q48hzzfan6albmckjifcrq23v2rkqlh9-test-file-2.txt15252026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15262026/10/05 12:09:38 WARN Refused reserved pin name=worker-x86_64-linux15272026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15282026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/my-app15292026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15302026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/app15312026/10/05 12:09:38 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15322026/10/05 12:09:38 INFO Received delete pin request method=DELETE path=/api/pins/app15332026/10/05 12:09:38 INFO lead: released remote=192.0.2.1:123415342026/10/05 12:09:38 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1535=== CONT TestService_AuthMiddleware_OIDC1536--- PASS: TestCreatePin_ReservedPins (0.45s)15372026/10/05 12:09:38 INFO Received delete pin request method=DELETE path=/api/pins/app15382026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15392026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15402026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15412026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15422026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15432026/10/05 12:09:38 INFO Deleted pin name=app15442026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15452026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy15462026/10/05 12:09:38 INFO Received create pin request method=POST path=/api/pins/deploy1547=== NAME TestClientWithDependencies1548 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2844080596/001/store/irvmwz9c97i3qnsv3q61x2cnr8npckxz-test-script15492026/10/05 12:09:38 INFO Received push request method=POST path=/api/pushes1550=== CONT TestCacheConfigHandler1551--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.26s)1552=== RUN TestCacheConfigHandler/full_config,_no_issuer1553=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1554=== RUN TestCacheConfigHandler/no_cache_url_configured1555=== PAUSE TestCacheConfigHandler/no_cache_url_configured1556=== RUN TestCacheConfigHandler/no_signing_keys1557=== PAUSE TestCacheConfigHandler/no_signing_keys1558=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1559=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1560=== CONT TestService_verifyS3Integrity15612026/10/05 12:09:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15622026/10/05 12:09:39 INFO Uploading gcp6wnk1mzrf8y1x35xcnqpa2cw2d93r-test-file-1.txt (160B)15632026/10/05 12:09:39 INFO Uploading q48hzzfan6albmckjifcrq23v2rkqlh9-test-file-2.txt (160B)15642026/10/05 12:09:39 INFO Uploading adp5vsp9g1734piy2rapza420rk1bvq6-test-file-0.txt (160B)1565=== NAME TestClientWithDependencies1566 client_integration_test.go:737: Found 1 dependencies (including self)15672026/10/05 12:09:39 INFO lead: acquired remote=192.0.2.1:123415682026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15692026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15702026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15712026/10/05 12:09:39 WARN Failed to register uploaded object key=q48hzzfan6albmckjifcrq23v2rkqlh9.ls error="server returned 404: 404 page not found\n"15722026/10/05 12:09:39 WARN Failed to register uploaded object key=adp5vsp9g1734piy2rapza420rk1bvq6.ls error="server returned 404: 404 page not found\n"15732026/10/05 12:09:39 WARN Failed to register uploaded object key=gcp6wnk1mzrf8y1x35xcnqpa2cw2d93r.ls error="server returned 404: 404 page not found\n"15742026/10/05 12:09:39 INFO Received create pin request method=POST path=/api/pins/deploy15752026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15762026/10/05 12:09:39 INFO Signed narinfos id=1 count=315772026/10/05 12:09:39 INFO Uploading 3 narinfos15782026/10/05 12:09:39 WARN Failed to register uploaded object key=q48hzzfan6albmckjifcrq23v2rkqlh9.narinfo error="server returned 404: 404 page not found\n"15792026/10/05 12:09:39 WARN Failed to register uploaded object key=adp5vsp9g1734piy2rapza420rk1bvq6.narinfo error="server returned 404: 404 page not found\n"15802026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete15812026/10/05 12:09:39 WARN Failed to register uploaded object key=gcp6wnk1mzrf8y1x35xcnqpa2cw2d93r.narinfo error="server returned 404: 404 page not found\n"15822026/10/05 12:09:39 INFO Upload complete. (95ms)1583=== NAME TestClientMultipleUploads1584 client_integration_test.go:491: Uploaded 3 paths in 131.888277ms1585=== NAME TestNARDeduplicationMetadataUploadBug1586 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1282803685/001/store/1k90xlqmxkpmjjadnqlr10jz4wkzjdy7-file1.txt1587--- PASS: TestObjectStatsTrigger (0.25s)1588=== CONT TestUploadHandlersRejectOversizedBody15892026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes15902026/10/05 12:09:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15912026/10/05 12:09:39 INFO Uploading irvmwz9c97i3qnsv3q61x2cnr8npckxz-test-script (136B)1592--- PASS: TestClientMultipleUploads (0.53s)1593=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15942026/10/05 12:09:39 WARN Failed to register uploaded object key=log/g0jgw7vqqmlmcdgl0fnqqbpwbphgm5dl-test-script.drv error="server returned 404: 404 page not found\n"15952026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15962026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15972026/10/05 12:09:39 WARN Failed to register uploaded object key=irvmwz9c97i3qnsv3q61x2cnr8npckxz.ls error="server returned 404: 404 page not found\n"15982026/10/05 12:09:39 INFO Signed narinfos id=1 count=115992026/10/05 12:09:39 INFO Uploading 1 narinfos16002026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete16012026/10/05 12:09:39 WARN Failed to register uploaded object key=irvmwz9c97i3qnsv3q61x2cnr8npckxz.narinfo error="server returned 404: 404 page not found\n"1602=== CONT TestClientIntegration1603--- PASS: TestReconnectLeavesObjectsUnlocked (0.28s)16042026/10/05 12:09:39 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket237735886/001/proxy.sock16052026/10/05 12:09:39 INFO Starting HTTP server address=127.0.0.1:4324316062026/10/05 12:09:39 INFO Upload complete. (85ms)1607--- PASS: TestPresentReportsOnlyClosureRoots (0.25s)1608=== CONT TestClientCADerivations16092026/10/05 12:09:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16102026/10/05 12:09:39 INFO Shutdown signal received, draining in-flight requests timeout=10s16112026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=016122026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period16132026/10/05 12:09:39 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=01614=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1615--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.27s)16162026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes16172026/10/05 12:09:39 INFO Vacuumed table table=pending_closures16182026/10/05 12:09:39 INFO Vacuumed table table=pending_objects16192026/10/05 12:09:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16202026/10/05 12:09:39 INFO Vacuumed table table=multipart_uploads16212026/10/05 12:09:39 INFO Uploading 1k90xlqmxkpmjjadnqlr10jz4wkzjdy7-file1.txt (160B)16222026/10/05 12:09:39 INFO Vacuumed table table=closures16232026/10/05 12:09:39 INFO Vacuumed table table=objects1624=== NAME TestClientWithDependencies1625 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2844080596/001/store) requires matching store prefix16262026/10/05 12:09:39 WARN Failed to register uploaded object key=1k90xlqmxkpmjjadnqlr10jz4wkzjdy7.ls error="server returned 404: 404 page not found\n"16272026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16282026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16292026/10/05 12:09:39 INFO Signed narinfos id=1 count=116302026/10/05 12:09:39 INFO Uploading 1 narinfos16312026/10/05 12:09:39 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo16322026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete16332026/10/05 12:09:39 WARN Failed to register uploaded object key=1k90xlqmxkpmjjadnqlr10jz4wkzjdy7.narinfo error="server returned 404: 404 page not found\n"16342026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures1635--- PASS: TestClientWithDependencies (0.56s)1636=== CONT TestCompleteMultipartUnregistered16372026/10/05 12:09:39 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo16382026/10/05 12:09:39 INFO Upload complete. (77ms)1639=== NAME TestNARDeduplicationMetadataUploadBug1640 metadata_upload_test.go:54: Retrieved narinfo from S3:1641 StorePath: /build/TestNARDeduplicationMetadataUploadBug1282803685/001/store/1k90xlqmxkpmjjadnqlr10jz4wkzjdy7-file1.txt1642 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1643 Compression: zstd1644 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1645 NarSize: 1601646 References: 1647 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1648=== CONT TestPendingClosureWriteTimeout1649--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.73s)1650=== RUN TestPendingClosureWriteTimeout/empty1651=== PAUSE TestPendingClosureWriteTimeout/empty1652=== RUN TestPendingClosureWriteTimeout/400_objects1653=== PAUSE TestPendingClosureWriteTimeout/400_objects1654=== RUN TestPendingClosureWriteTimeout/670k_objects1655=== PAUSE TestPendingClosureWriteTimeout/670k_objects1656=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1657=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1658=== CONT TestResolveDBConnectionString/flag_wins1659=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1660=== CONT TestResolveDBConnectionString/nothing_configured1661=== CONT TestResolveDBConnectionString/file_when_flag_empty1662=== CONT TestResolveDBConnectionString/missing_file_is_an_error1663=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1664--- PASS: TestResolveDBConnectionString (0.00s)1665 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1666 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1667 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1668 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1669 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1670=== NAME TestNARDeduplicationMetadataUploadBug1671 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1672 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1673 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1674--- PASS: TestConcurrentPinUpdatesAgree (0.74s)1675=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1676=== NAME TestNARDeduplicationMetadataUploadBug1677 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1282803685/001/store/k4c7axqxz3zv0415rmg1fpgv4yicj86y-file2.txt16782026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16792026/10/05 12:09:39 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2Ljg1NDQ4MmIxLWQ0ODYtNGI2NC1hY2M3LWI2YjdlN2IxODdjN3gxNzkxMjAyMTc3NTQ4MjQxMTAy parts=1016802026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete16812026/10/05 12:09:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16822026/10/05 12:09:39 WARN mTLS auth: bound subjects configured but subject DN unavailable16832026/10/05 12:09:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1684--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.19s)1685=== CONT TestIsValidCachePath/nar_bz21686=== CONT TestIsValidCachePath/index.html1687=== CONT TestIsValidCachePath/realisation1688=== CONT TestIsValidCachePath/short_hash1689=== CONT TestIsValidCachePath/log1690=== CONT TestIsValidCachePath/leading_slash1691=== CONT TestIsValidCachePath/ls1692=== CONT TestIsValidCachePath/traversal_in_middle1693=== CONT TestIsValidCachePath/empty1694=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1695=== CONT TestIsValidCachePath/invalid_char_u1696=== CONT TestIsValidCachePath/nix-cache-info1697=== CONT TestIsValidCachePath/wrong_extension1698=== CONT TestIsValidCachePath/nar_uncompressed1699=== CONT TestIsValidCachePath/invalid_char_e1700=== CONT TestIsValidCachePath/traversal_parent1701=== CONT TestIsValidCachePath/nar_xz1702=== CONT TestIsValidCachePath/random_path1703=== CONT TestIsValidCachePath/nar_zst1704=== CONT TestIsValidCachePath/narinfo1705=== CONT TestProxyWriteTimeout/1_GiB_nar1706--- PASS: TestIsValidCachePath (0.00s)1707 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1708 --- PASS: TestIsValidCachePath/index.html (0.00s)1709 --- PASS: TestIsValidCachePath/realisation (0.00s)1710 --- PASS: TestIsValidCachePath/short_hash (0.00s)1711 --- PASS: TestIsValidCachePath/log (0.00s)1712 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1713 --- PASS: TestIsValidCachePath/ls (0.00s)1714 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1715 --- PASS: TestIsValidCachePath/empty (0.00s)1716 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1717 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1718 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1719 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1720 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1721 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1722 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1723 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1724 --- PASS: TestIsValidCachePath/random_path (0.00s)1725 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1726 --- PASS: TestIsValidCachePath/narinfo (0.00s)1727=== CONT TestProxyWriteTimeout/unknown_size1728=== CONT TestProxyWriteTimeout/narinfo1729=== CONT TestProxyWriteTimeout/10_GiB_nar1730=== CONT TestIsValidUploadKey/narinfo1731=== CONT TestIsValidUploadKey/unknown_type1732--- PASS: TestProxyWriteTimeout (0.00s)1733 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1734 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1735 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1736 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1737=== CONT TestIsValidUploadKey/empty_key1738=== CONT TestIsValidUploadKey/absolute1739=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1740=== CONT TestIsValidUploadKey/traversal1741=== CONT TestIsValidUploadKey/traversal_nar1742=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1743=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1744=== CONT TestIsValidUploadKey/build_log_equals1745=== CONT TestIsValidUploadKey/nar_xz1746=== CONT TestIsValidUploadKey/build_log_plus_in_name1747=== CONT TestIsValidUploadKey/index.html1748=== CONT TestIsValidUploadKey/build_log1749=== CONT TestIsValidUploadKey/nix-cache-info1750=== CONT TestIsValidUploadKey/realisation_plus_in_output1751=== CONT TestIsValidUploadKey/build_log_question_mark1752=== CONT TestIsValidUploadKey/realisation1753=== CONT TestIsValidUploadKey/build_log_home-manager_file1754=== CONT TestIsValidUploadKey/nar_zst1755=== CONT TestIsValidUploadKey/listing1756=== CONT TestIsValidUploadKey/nar_plain1757=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1758--- PASS: TestIsValidUploadKey (0.00s)1759 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1760 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1761 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1762 --- PASS: TestIsValidUploadKey/absolute (0.00s)1763 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1764 --- PASS: TestIsValidUploadKey/traversal (0.00s)1765 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1766 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1767 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1768 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1769 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1770 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1771 --- PASS: TestIsValidUploadKey/index.html (0.00s)1772 --- PASS: TestIsValidUploadKey/build_log (0.00s)1773 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1774 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1775 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1776 --- PASS: TestIsValidUploadKey/realisation (0.00s)1777 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1778 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1779 --- PASS: TestIsValidUploadKey/listing (0.00s)1780 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)17812026/10/05 12:09:39 INFO Received request for more parts method=POST path=/1782=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17832026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/1784=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17852026/10/05 12:09:39 INFO Received uploads request method=POST path=/1786=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1787=== CONT TestServerTLSConfig/no_client_CA17882026/10/05 12:09:39 INFO Received uploads request method=POST path=/1789--- PASS: TestPush_CompleteCommitsEveryRoot (2.15s)1790=== CONT TestServerTLSConfig/missing_CA_file1791=== CONT TestServerTLSConfig/not_a_PEM_file1792=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1793--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1794 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1795 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1796 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1797 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1798=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1799--- PASS: TestServerTLSConfig (0.00s)1800 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1801 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1802 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1803=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18042026/10/05 12:09:39 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]1805=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1806=== CONT TestService_RequireScope_OIDC/static_token_may_write1807=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1808=== CONT TestService_RequireScope_OIDC/reader_may_read1809=== CONT TestService_RequireScope_OIDC/ops_may_admin1810=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1811=== CONT TestService_RequireScope_OIDC/static_token_may_admin1812=== CONT TestService_RequireScope_OIDC/writer_implies_read1813=== CONT TestService_RequireScope_OIDC/reader_may_not_write1814=== CONT TestService_RequireScope_OIDC/ops_may_not_write1815=== CONT TestService_RequireScope_OIDC/builder_may_write1816=== CONT TestGCEndsOnShutdown/before_the_run1817=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18182026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes18192026/10/05 12:09:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18202026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18212026/10/05 12:09:39 WARN Failed to register uploaded object key=k4c7axqxz3zv0415rmg1fpgv4yicj86y.ls error="server returned 404: 404 page not found\n"18222026/10/05 12:09:39 INFO Signed narinfos id=2 count=118232026/10/05 12:09:39 INFO Uploading 1 narinfos1824--- PASS: TestService_RequireScope_OIDC (0.54s)1825 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)18392026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/2/complete18402026/10/05 12:09:39 WARN Failed to register uploaded object key=k4c7axqxz3zv0415rmg1fpgv4yicj86y.narinfo error="server returned 404: 404 page not found\n"18412026/10/05 12:09:39 INFO Upload complete. (73ms)18422026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures1843=== NAME TestNARDeduplicationMetadataUploadBug1844 metadata_upload_test.go:76: Retrieved narinfo from S3:1845 StorePath: /build/TestNARDeduplicationMetadataUploadBug1282803685/001/store/k4c7axqxz3zv0415rmg1fpgv4yicj86y-file2.txt1846 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1847 Compression: zstd1848 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1849 NarSize: 1601850 References: 1851 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1852 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1853 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1854 {"version":1,"root":{"type":"regular","size":44}}1855=== NAME TestClientIntegration1856 client_integration_test.go:334: Created store path: /build/TestClientIntegration2120899978/002/store/37azphdws37ly8q7yw43w5332blrpcsc-test-file.txt18572026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18582026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18592026/10/05 12:09:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst18602026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1861--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.22s)1862=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1863=== CONT TestPush_RejectsBadRequests/root_not_in_objects1864--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)18652026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes1866=== CONT TestPush_RejectsBadRequests/bad_root18672026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes1868=== CONT TestPush_RejectsBadRequests/no_roots18692026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes1870=== CONT TestPush_RejectsBadRequests/no_objects18712026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes1872=== CONT TestParseSingleRange/unknown_unit1873=== CONT TestParseSingleRange/start_past_EOF1874=== CONT TestParseSingleRange/start_far_past_EOF1875=== CONT TestParseSingleRange/single_byte1876=== CONT TestParseSingleRange/suffix_exceeds_size1877=== CONT TestParseSingleRange/suffix1878=== CONT TestParseSingleRange/open-ended1879=== CONT TestParseSingleRange/closed1880=== CONT TestParseSingleRange/malformed_end_before_start1881=== CONT TestParseSingleRange/end_clamped_to_size1882=== CONT TestParseSingleRange/malformed_both_empty1883=== CONT TestParseSingleRange/multi-range_ignored1884=== CONT TestParseSingleRange/malformed_no_dash1885=== CONT TestParseSingleRange/none1886=== CONT TestClientErrorHandling/ServerNotAvailable1887--- PASS: TestParseSingleRange (0.00s)1888 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1889 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1890 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1891 --- PASS: TestParseSingleRange/single_byte (0.00s)1892 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1893 --- PASS: TestParseSingleRange/suffix (0.00s)1894 --- PASS: TestParseSingleRange/open-ended (0.00s)1895 --- PASS: TestParseSingleRange/closed (0.00s)1896 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1897 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1898 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1899 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1900 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1901 --- PASS: TestParseSingleRange/none (0.00s)19022026/10/05 12:09:39 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LmI5MmI3YWM3LWU5ZGMtNDkyZi1iY2MxLTFmZjk1MGY0NDM4MXgxNzkxMjAyMTc4NzQzMDk0NDEx error="Get \"http://127.0.0.1:1/bucket45/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19032026/10/05 12:09:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LmEwNGVlNTY4LTMxNjQtNDlkYS05NDViLTZjNTRmNWE2NDhmM3gxNzkxMjAyMTc4NzIxMjM2NjU2 parts=1219042026/10/05 12:09:39 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjQ2YTMyNzg2LTYwYzctNDZhNy1iY2E4LTkzMDE0MmRhZjFiNXgxNzkxMjAyMTc4MTk0OTc0NTc3 parts=1019052026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete19062026/10/05 12:09:39 INFO Received cleanup request method=DELETE path=/api/pending_closures1907--- PASS: TestCompleteMultipartUnregistered (0.20s)1908=== CONT TestClientErrorHandling/InvalidStorePath1909=== NAME TestClientCADerivations1910 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2106234938/001/store/kns8cvhyndf4mws7db10nm2k1pbna04s-ca-test1911=== NAME TestOrphanedObjectsGC1912 orphaned_objects_gc_test.go:290: GC Test Summary:1913 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1914 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1915 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1916 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1917 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects19182026/10/05 12:09:39 INFO Aborted multipart uploads count=1 kept=019192026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes1920--- PASS: TestPush_RejectsBadRequests (0.31s)1921 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1922 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1923 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1924 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19252026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures19262026/10/05 12:09:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42195/oidc19272026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=01928--- PASS: TestOrphanedObjectsGC (0.58s)1929=== CONT TestClientErrorHandling/InvalidAuthToken19302026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period1931=== CONT TestCacheConfigHandler/no_signing_keys1932--- PASS: TestRedundantMultipartUpload (1.72s)1933=== NAME TestClientCADerivations1934 client_ca_test.go:139: Found 1 dependencies (including self)1935=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1936=== CONT TestCacheConfigHandler/no_cache_url_configured1937=== CONT TestCacheConfigHandler/full_config,_no_issuer1938=== CONT TestPendingClosureWriteTimeout/400_objects1939--- PASS: TestCacheConfigHandler (0.00s)1940 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1941 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1942 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1943 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1944=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19452026/10/05 12:09:39 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"19462026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures19472026/10/05 12:09:39 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=019482026/10/05 12:09:39 INFO Vacuumed table table=pending_closures19492026/10/05 12:09:39 INFO Vacuumed table table=pending_objects19502026/10/05 12:09:39 INFO Vacuumed table table=multipart_uploads19512026/10/05 12:09:39 INFO Vacuumed table table=closures19522026/10/05 12:09:39 INFO Vacuumed table table=objects19532026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes19542026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=019552026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period19562026/10/05 12:09:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19572026/10/05 12:09:39 INFO Uploading 37azphdws37ly8q7yw43w5332blrpcsc-test-file.txt (152B)19582026/10/05 12:09:39 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=019592026/10/05 12:09:39 INFO Vacuumed table table=pending_closures19602026/10/05 12:09:39 INFO Vacuumed table table=pending_objects19612026/10/05 12:09:39 INFO Vacuumed table table=multipart_uploads19622026/10/05 12:09:39 INFO Vacuumed table table=closures19632026/10/05 12:09:39 INFO Vacuumed table table=objects19642026/10/05 12:09:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19652026/10/05 12:09:39 WARN Failed to register uploaded object key=37azphdws37ly8q7yw43w5332blrpcsc.ls error="server returned 404: 404 page not found\n"19662026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19672026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19682026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=019692026/10/05 12:09:39 INFO Signed narinfos id=1 count=119702026/10/05 12:09:39 INFO Uploading 1 narinfos19712026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period19722026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete19732026/10/05 12:09:39 WARN Failed to register uploaded object key=37azphdws37ly8q7yw43w5332blrpcsc.narinfo error="server returned 404: 404 page not found\n"1974=== CONT TestPendingClosureWriteTimeout/empty1975=== CONT TestPendingClosureWriteTimeout/670k_objects19762026/10/05 12:09:39 INFO Upload complete. (88ms)19772026/10/05 12:09:39 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=019782026/10/05 12:09:39 INFO Vacuumed table table=pending_closures19792026/10/05 12:09:39 INFO Vacuumed table table=pending_objects1980--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1981 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.29s)1982 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)19832026/10/05 12:09:39 INFO Vacuumed table table=multipart_uploads19842026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=019852026/10/05 12:09:39 INFO Vacuumed table table=closures19862026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period19872026/10/05 12:09:39 INFO Vacuumed table table=objects1988=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1989=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1990=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1991=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1992=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1993=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1994=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1995=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1996=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19972026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/19982026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes19992026/10/05 12:09:39 INFO Received request for more parts method=POST path=/20002026/10/05 12:09:39 INFO Received uploads request method=POST path=/20012026/10/05 12:09:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.164665ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20022026/10/05 12:09:39 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:46339/bucket92/?delete=\": context canceled"20032026/10/05 12:09:39 INFO All 1 paths already cached2004=== NAME TestClientIntegration2005 client_integration_test.go:360: Retrieved narinfo from S3:2006 StorePath: /build/TestClientIntegration2120899978/002/store/37azphdws37ly8q7yw43w5332blrpcsc-test-file.txt2007 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2008 Compression: zstd2009 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12010 NarSize: 1522011 References: 2012 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk120132026/10/05 12:09:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20142026/10/05 12:09:39 INFO Uploading kns8cvhyndf4mws7db10nm2k1pbna04s-ca-test (144B)2015 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)2016 client_integration_test.go:361: Decompressed .ls content (64 bytes):2017 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}20182026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20192026/10/05 12:09:39 WARN Failed to register uploaded object key=log/mrd0ffz683766pjp0xqqzxs1d0dn79z5-ca-test.drv error="server returned 404: 404 page not found\n"20202026/10/05 12:09:39 WARN Failed to register uploaded object key=kns8cvhyndf4mws7db10nm2k1pbna04s.ls error="server returned 404: 404 page not found\n"20212026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20222026/10/05 12:09:39 INFO Signed narinfos id=1 count=120232026/10/05 12:09:39 INFO Uploading 1 narinfos20242026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/1/complete20252026/10/05 12:09:39 WARN Failed to register uploaded object key=kns8cvhyndf4mws7db10nm2k1pbna04s.narinfo error="server returned 404: 404 page not found\n"20262026/10/05 12:09:39 INFO Upload complete. (211ms)20272026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=020282026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period2029=== NAME TestClientCADerivations2030 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2106234938/001/store/kns8cvhyndf4mws7db10nm2k1pbna04s-ca-test2031 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2032 Compression: zstd2033 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2034 NarSize: 1442035 References: 2036 Deriver: /build/TestClientCADerivations2106234938/001/store/mrd0ffz683766pjp0xqqzxs1d0dn79z5-ca-test.drv2037 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2038 client_ca_test.go:185: Checking for realisation files in S3...2039 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2040 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20412026-10-05 12:09:39.680 UTC [1783] ERROR: canceling statement due to user request20422026-10-05 12:09:39.680 UTC [1783] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block20432026-10-05 12:09:39.680 UTC [1783] STATEMENT: -- name: MarkStaleObjects :execrows2044 WITH RECURSIVE ct AS (2045 SELECT timezone('UTC', now()) AS now2046 ),2047 closure_reach AS (2048 -- Start with all closure keys2049 SELECT o.key, o.refs2050 FROM objects o2051 INNER JOIN closures c ON o.key = c.key2052 UNION2053 -- Recursively add all referenced objects2054 SELECT o.key, o.refs2055 FROM objects o2056 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2057 ),2058 reachable_objects AS (2059 SELECT DISTINCT key FROM closure_reach2060 ),2061 stale_objects AS (2062 SELECT o.key2063 FROM objects AS o, ct2064 WHERE2065 NOT EXISTS (2066 SELECT 12067 FROM reachable_objects ro2068 WHERE ro.key = o.key2069 )2070 AND NOT EXISTS (2071 SELECT 12072 FROM pending_objects AS po2073 WHERE po.key = o.key2074 )2075 AND o.deleted_at IS NULL -- Only mark fresh objects2076 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2077 FOR UPDATE2078 )2079 UPDATE objects2080 SET2081 deleted_at = ct.now,2082 first_deleted_at = COALESCE(first_deleted_at, ct.now)2083 FROM stale_objects, ct2084 WHERE objects.key = stale_objects.key2085 20862026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes2087--- PASS: TestGCEndsOnShutdown (0.00s)2088 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.32s)2089 --- PASS: TestGCEndsOnShutdown/before_the_run (0.33s)2090 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.33s)20912026/10/05 12:09:39 INFO Object in database but missing from S3 key=37azphdws37ly8q7yw43w5332blrpcsc.ls20922026/10/05 12:09:39 WARN Found objects in DB but missing from S3, will re-upload count=120932026/10/05 12:09:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20942026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/2/complete20952026/10/05 12:09:39 WARN Failed to register uploaded object key=37azphdws37ly8q7yw43w5332blrpcsc.ls error="server returned 404: 404 page not found\n"20962026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures20972026/10/05 12:09:39 INFO Upload complete. (65ms)2098=== NAME TestClientIntegration2099 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)2100 client_integration_test.go:389: Decompressed .ls content (49 bytes):2101 {"version":1,"root":{"type":"regular","size":39}}2102=== NAME TestClientCADerivations2103 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2104 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2105 error: binary cache 's3://bucket86?endpoint=http://localhost:46339®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2106234938/001/store'2106 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 121072026/10/05 12:09:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2108=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2109=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2110=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2111=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2112=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2113=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2114=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2115=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2116=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2117=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2118=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2119=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21202026/10/05 12:09:39 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]21212026/10/05 12:09:39 WARN Authentication failed token_preview=eyJhbGciOi...IPIPHH0-zg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]21222026/10/05 12:09:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LjQ4MDQyYmJkLWQzOTAtNDc0MC1hZGQxLTA3MzI3YTMzODhmMHgxNzkxMjAyMTc5MTk2MDAzNjE1 parts=1021232026/10/05 12:09:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21242026/10/05 12:09:39 INFO Completed upload id=12125--- PASS: TestClientCADerivations (0.66s)21262026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures2127--- PASS: TestService_AuthMiddleware_OIDC (0.83s)2128 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2129 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2130 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2131 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)21322026/10/05 12:09:39 INFO Received uploads request method=POST path=/api/pending_closures21332026/10/05 12:09:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.305072ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21342026/10/05 12:09:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo21352026/10/05 12:09:39 WARN Found objects in DB but missing from S3, will re-upload count=121362026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes21372026/10/05 12:09:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21382026/10/05 12:09:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21392026/10/05 12:09:39 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21402026/10/05 12:09:39 INFO Completed upload id=321412026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/3/complete21422026/10/05 12:09:39 WARN Failed to register uploaded object key=37azphdws37ly8q7yw43w5332blrpcsc.ls error="server returned 404: 404 page not found\n"21432026/10/05 12:09:39 INFO Upload complete. (52ms)2144=== NAME TestClientIntegration2145 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2146 client_integration_test.go:405: Decompressed .ls content (49 bytes):2147 {"version":1,"root":{"type":"regular","size":39}}2148--- PASS: TestService_verifyS3Integrity (0.84s)21492026/10/05 12:09:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21502026/10/05 12:09:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021512026/10/05 12:09:39 INFO Received create pin request method=POST path=/api/pins/myapp21522026/10/05 12:09:39 INFO Received push request method=POST path=/api/pushes21532026/10/05 12:09:39 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1488729013/001/store/dy0n2by65361vn7c4cackqgr8wyjbr9z-pinned-file.txt narinfo_key=dy0n2by65361vn7c4cackqgr8wyjbr9z.narinfo21542026/10/05 12:09:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21552026/10/05 12:09:39 INFO Uploading fqdavqkiq3lhciys65dc4xbdhf0ya2p4-lost-commit.txt (152B)21562026/10/05 12:09:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures21572026/10/05 12:09:39 INFO Garbage collection started21582026/10/05 12:09:39 INFO Aborted multipart uploads count=0 kept=021592026/10/05 12:09:39 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721621602026/10/05 12:09:39 WARN Force mode enabled - objects will be deleted immediately without grace period21612026/10/05 12:09:39 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21622026/10/05 12:09:39 WARN Failed to register uploaded object key=fqdavqkiq3lhciys65dc4xbdhf0ya2p4.ls error="server returned 404: 404 page not found\n"21632026/10/05 12:09:39 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21642026/10/05 12:09:39 INFO Signed narinfos id=4 count=121652026/10/05 12:09:39 INFO Uploading 1 narinfos21662026/10/05 12:09:39 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=021672026/10/05 12:09:39 INFO Vacuumed table table=pending_closures21682026/10/05 12:09:39 INFO Vacuumed table table=pending_objects21692026/10/05 12:09:39 INFO Vacuumed table table=multipart_uploads21702026/10/05 12:09:39 INFO Vacuumed table table=closures21712026/10/05 12:09:39 INFO Received complete push request method=POST path=/api/pushes/4/complete21722026/10/05 12:09:39 WARN Failed to register uploaded object key=fqdavqkiq3lhciys65dc4xbdhf0ya2p4.narinfo error="server returned 404: 404 page not found\n"21732026/10/05 12:09:39 INFO Vacuumed table table=objects21742026/10/05 12:09:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:44371/api/pushes/4/complete\": EOF" url=http://127.0.0.1:44371/api/pushes/4/complete2175--- PASS: TestReadProxyNarinfo (1.44s)2176=== NAME TestLeadElectsOneAndHandsOver2177 farm_test.go:158: b did not announce leadership 21 heartbeats after taking the lock: {Lead:false}21782026/10/05 12:09:40 INFO lead: released remote=192.0.2.1:12342179--- FAIL: TestLeadElectsOneAndHandsOver (2.58s)21802026/10/05 12:09:40 INFO Received complete push request method=POST path=/api/pushes/4/complete21812026-10-05 12:09:40.082 UTC [1454] ERROR: Push does not exist: id=421822026-10-05 12:09:40.082 UTC [1454] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE21832026-10-05 12:09:40.082 UTC [1454] STATEMENT: -- name: CommitPush :exec2184 SELECT commit_push($1::bigint)2185 21862026/10/05 12:09:40 INFO Upload complete. (175ms)2187=== NAME TestClientIntegration2188 client_integration_test.go:435: Retrieved narinfo from S3:2189 StorePath: /build/TestClientIntegration2120899978/002/store/fqdavqkiq3lhciys65dc4xbdhf0ya2p4-lost-commit.txt2190 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2191 Compression: zstd2192 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2193 NarSize: 1522194 References: 2195 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2196 client_integration_test.go:438: Testing garbage collection...21972026/10/05 12:09:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21982026/10/05 12:09:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures21992026/10/05 12:09:40 INFO Garbage collection started22002026/10/05 12:09:40 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YjhkYjk4MmUtYTZjYy00YTdlLWE1OTItYjE0OWNiYjk2MjU2LmQ4ZGQ1YTg3LTYzNzYtNDZmYi05ZjZmLWRkZjZiM2JiZmE0MXgxNzkxMjAyMTc5NDAzMTkzNzQ1 parts=1022012026/10/05 12:09:40 INFO Received complete push request method=POST path=/api/pushes/2/complete22022026/10/05 12:09:40 INFO Aborted multipart uploads count=0 kept=022032026/10/05 12:09:40 WARN Force mode enabled - objects will be deleted immediately without grace period22042026/10/05 12:09:40 INFO Received create pin request method=POST path=/api/pins/deploy2205--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.35s)22062026/10/05 12:09:40 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo22072026/10/05 12:09:40 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=022082026/10/05 12:09:40 INFO Vacuumed table table=pending_closures22092026/10/05 12:09:40 INFO Vacuumed table table=pending_objects22102026/10/05 12:09:40 INFO Vacuumed table table=multipart_uploads22112026/10/05 12:09:40 INFO Vacuumed table table=closures22122026/10/05 12:09:40 INFO Vacuumed table table=objects2213--- PASS: TestCreatePinRejectsBadInput (1.41s)22142026/10/05 12:09:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.016353ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2215=== NAME TestOrphanedObjectsGCStressTest2216 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2217 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2218 orphaned_objects_gc_test.go:509: Stress test completed successfully:2219 orphaned_objects_gc_test.go:510: - Active objects preserved: 202220 orphaned_objects_gc_test.go:511: - Objects deleted: 2102221 orphaned_objects_gc_test.go:512: - Total GC'd: 2102222--- PASS: TestOrphanedObjectsGCStressTest (2.53s)2223--- PASS: TestPendingClosureWriteTimeout (0.00s)2224 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2225 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2226 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2227 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.12s)22282026/10/05 12:09:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.60298383s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22292026/10/05 12:09:41 WARN Rate limiter enabled after throttle name=s3-test rate=522302026/10/05 12:09:41 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2231=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2232 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102233 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002234--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.12s)2235=== NAME TestPinProtectsFromGC2236 client_integration_test.go:976: Pin successfully protected closure from garbage collection2237--- PASS: TestPinProtectsFromGC (4.78s)2238--- PASS: TestConnectWaitsForAPeerMigration (5.35s)22392026/10/05 12:09:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02240=== NAME TestClientIntegration2241 client_integration_test.go:445: Objects in database after GC:2242 client_integration_test.go:445: Successfully deleted all objects with GC --force2243--- PASS: TestClientIntegration (3.02s)22442026/10/05 12:09:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/10/05 12:09:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.233277ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2246--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.73s)22472026/10/05 12:09:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.43463ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22482026/10/05 12:09:43 INFO Aborted multipart uploads count=1 kept=022492026/10/05 12:09:43 INFO Received cleanup request method=DELETE path=/api/pending_closures22502026/10/05 12:09:43 INFO Aborted multipart uploads count=1 kept=02251--- PASS: TestPendingCleanupUsesOneCutoff (6.45s)22522026/10/05 12:09:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.812121ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22532026/10/05 12:09:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.554599491s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22542026/10/05 12:09: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"22552026/10/05 12:09:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22562026/10/05 12:09:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.20338ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22572026/10/05 12:09:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.412042ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/10/05 12:09:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=864.095601ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/10/05 12:09:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.504104984s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22602026/10/05 12:09:48 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22612026/10/05 12:09:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.930066ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22622026/10/05 12:09:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.203517ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22632026/10/05 12:09:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.485288ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22642026/10/05 12:09:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.657688186s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2265--- PASS: TestClientErrorHandling (0.00s)2266 --- PASS: TestClientErrorHandling/InvalidStorePath (0.36s)2267 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.48s)2268 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.46s)2269--- PASS: TestUploadHandlersRejectOversizedBody (0.55s)2270 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.88s)2271 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.88s)2272 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (13.35s)2273FAIL2274{"timestamp":"2026-10-05T12:09:52.953337414Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41024","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(194)"}2275{"timestamp":"2026-10-05T12:09:52.953552596Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41018","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(208)"}2276{"timestamp":"2026-10-05T12:09:52.953554396Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41122","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}2277{"timestamp":"2026-10-05T12:09:52.953576096Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41036","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}2278{"timestamp":"2026-10-05T12:09:52.953727057Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:39820","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}22792026-10-05 12:09:53.256 UTC [175] LOG: received smart shutdown request22802026-10-05 12:09:53.260 UTC [175] LOG: background worker "logical replication launcher" (PID 185) exited with exit code 122812026-10-05 12:09:53.273 UTC [180] LOG: shutting down22822026-10-05 12:09:53.273 UTC [180] LOG: checkpoint starting: shutdown immediate22832026-10-05 12:09:54.157 UTC [180] LOG: checkpoint complete: wrote 10571 buffers (64.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.185 s, sync=0.667 s, total=0.885 s; sync files=33697, longest=0.002 s, average=0.001 s; distance=471748 kB, estimate=471748 kB; lsn=0/1E416E70, redo lsn=0/1E416E7022842026-10-05 12:09:54.233 UTC [175] LOG: database system is shut down