niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #446
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.25s)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:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.77s)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.03s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestDoServerRequestAttachesToken137=== CONT TestScriptTokenDoesNotWaitForItsChildren138=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs139=== CONT TestScriptTokenEmptyCommand140--- PASS: TestScriptTokenEmptyCommand (0.00s)141=== CONT TestScriptTokenScriptFails142=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess143=== CONT TestScriptTokenBadJSON144=== CONT TestScriptTokenCachesUntilRefresh145=== CONT TestScriptTokenNoExpiryRerunsEveryCall146=== CONT TestTruncatedNARDumpIsNotCompleted147=== CONT TestFileTokenEmpty148=== CONT TestRateLimiterFeedback149=== RUN TestRateLimiterFeedback/429_enables_limiter150=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent151=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier152=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier153=== CONT TestPathInfoCACompatibility154=== RUN TestPathInfoCACompatibility/null_ca_field155=== CONT TestCompletePendingClosure_NotFoundWithoutKey156=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up157=== CONT TestParsePathInfoJSON158=== RUN TestParsePathInfoJSON/Nix_format159=== PAUSE TestParsePathInfoJSON/Nix_format160=== RUN TestParsePathInfoJSON/Lix_format161=== CONT TestPathInfoHashCompatibility162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== PAUSE TestParsePathInfoJSON/Lix_format164=== RUN TestParsePathInfoJSON/empty_input165=== CONT TestConvertHashToNix32166=== RUN TestConvertHashToNix32/SRI_format_to_Nix32167=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32168=== RUN TestConvertHashToNix32/already_Nix32_format169=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up171=== PAUSE TestPathInfoCACompatibility/null_ca_field172=== RUN TestPathInfoCACompatibility/old_string_format_-_text173=== PAUSE TestParsePathInfoJSON/empty_input174=== CONT TestEncodeNixBase32175=== RUN TestEncodeNixBase32/test_string_hash176=== PAUSE TestEncodeNixBase32/test_string_hash177=== RUN TestEncodeNixBase32/empty_input178=== PAUSE TestConvertHashToNix32/already_Nix32_format179=== RUN TestConvertHashToNix32/invalid_format180=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon181=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon182=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI183=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier184=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier185=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client186=== PAUSE TestEncodeNixBase32/empty_input187=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text188=== RUN TestParsePathInfoJSON/whitespace_only189=== PAUSE TestParsePathInfoJSON/whitespace_only190=== CONT TestDumpPathSingleFile191=== CONT TestUploadMultipart_SupersededByPeer192=== RUN TestUploadMultipart_SupersededByPeer/exists193=== PAUSE TestUploadMultipart_SupersededByPeer/exists194=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== RUN TestParsePathInfoJSON/invalid_JSON197=== CONT TestDumpPathMatchesNix198=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== PAUSE TestConvertHashToNix32/invalid_format200=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512202=== CONT TestPartSizeForNAR203=== RUN TestPartSizeForNAR/zero_stays_at_minimum204=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum205=== RUN TestPartSizeForNAR/small_stays_at_minimum206=== CONT TestSupersededNARStillUploadsListing207=== RUN TestSupersededNARStillUploadsListing/small_NAR208=== PAUSE TestPartSizeForNAR/small_stays_at_minimum209=== PAUSE TestSupersededNARStillUploadsListing/small_NAR210=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum211=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum212=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts213=== RUN TestSupersededNARStillUploadsListing/dump_cut_short214=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short215=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts216=== RUN TestPartSizeForNAR/1_TiB217=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails218=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails219=== PAUSE TestPartSizeForNAR/1_TiB220=== RUN TestPartSizeForNAR/5_TiB_S3_max_object221=== CONT TestUploadMultipart_FailedPartBufferNotReused222=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object223=== RUN TestPartSizeForNAR/capped_at_5_GiB224=== PAUSE TestPartSizeForNAR/capped_at_5_GiB225=== CONT TestUploadMultipart_PartsInParallel226=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client227=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client228=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client229=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure230=== RUN TestPathInfoCACompatibility/new_structured_format_-_text231=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text232=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method234=== RUN TestUploadMultipart_SupersededByPeer/missing235=== PAUSE TestUploadMultipart_SupersededByPeer/missing236=== CONT TestStreamPushRequestLine237=== CONT TestUploadMultipart_ProducerErrorIsNotEOF238=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part239=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part240=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary241=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary242=== CONT TestScriptTokenEmptyToken243=== PAUSE TestParsePathInfoJSON/invalid_JSON244=== CONT TestFileTokenReadsAndCaches245=== CONT TestFilterOversizedClosures246=== RUN TestFilterOversizedClosures/no_limit_keeps_everything247=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything248=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped249=== CONT TestParsePathInfoJSONMultiplePaths250=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths251=== CONT TestGetStorePathHash252=== RUN TestGetStorePathHash/valid_store_path253=== PAUSE TestGetStorePathHash/valid_store_path254=== RUN TestGetStorePathHash/basename_without_hyphen_should_error255=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths257=== CONT TestEncodeNixBase32WithRealHash258--- PASS: TestEncodeNixBase32WithRealHash (0.00s)259=== CONT TestFileTokenMissing260=== RUN TestFilterOversizedClosures/all_closures_skipped261=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error262=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error263=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error264=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error265=== PAUSE TestFilterOversizedClosures/all_closures_skipped266=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error267=== CONT TestStaticToken268--- PASS: TestStaticToken (0.00s)269=== CONT TestSetClientTLSDoesNotMutateDefaultTransport270--- PASS: TestFileTokenEmpty (0.08s)271=== CONT TestSetClientTLS272=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs273=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout274=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout275=== PAUSE TestRateLimiterFeedback/429_enables_limiter276=== CONT TestStreamPushStopsOnCancel277=== RUN TestStreamPushStopsOnCancel/waiting_for_input278=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input279=== RUN TestRateLimiterFeedback/503_enables_limiter280=== CONT TestSetClientTLSErrors281--- PASS: TestScriptTokenScriptFails (0.10s)282=== CONT TestStreamPushStopsWhenCanceled283--- PASS: TestStreamPushStopsWhenCanceled (0.00s)284=== CONT TestClientSignaturesByStorePath285--- PASS: TestClientSignaturesByStorePath (0.00s)286=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel287--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.09s)288=== CONT TestStreamPushReportsSignatures289=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths290--- PASS: TestFileTokenMissing (0.05s)291=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry292--- PASS: TestFileTokenReadsAndCaches (0.08s)293=== CONT TestCaseHackSuffix294=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot295=== CONT TestDumpPathWriterError296--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.08s)297=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica298--- PASS: TestStreamPushReportsSignatures (0.24s)299=== CONT TestRegisterUploadedObjectReusesConnections300=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths301=== RUN TestSetClientTLS/rejects_connection_without_client_cert302=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert303=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA304=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA305=== RUN TestSetClientTLS/preserves_debug_logging_transport306=== CONT TestShellSplit307--- PASS: TestShellSplit (0.00s)308=== PAUSE TestSetClientTLS/preserves_debug_logging_transport309=== CONT TestStreamPushGivesUpOnDeadServer310=== CONT TestStreamPushIsolatesFailures311--- PASS: TestStreamPushIsolatesFailures (0.00s)312=== CONT TestStreamPushReportsSkippedPaths313--- PASS: TestStreamPushReportsSkippedPaths (0.00s)314=== CONT TestStreamPushReportsEveryPath315--- PASS: TestStreamPushReportsEveryPath (0.00s)316=== CONT TestShellSplitErrors317--- PASS: TestShellSplitErrors (0.00s)318=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun319=== PAUSE TestRateLimiterFeedback/503_enables_limiter320=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter321=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot322=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot323=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter324=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter325=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot326=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot327=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot328=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot329=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot330=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken331=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken332=== CONT TestDoWithRetry_FinalResponseBodyReadable333--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)334=== CONT TestStreamPushBatchesUnderLoad335=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false336=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false337=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true338=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true339=== CONT TestRetryTimeoutOutlastsMaxRetries340--- PASS: TestDoServerRequestAttachesToken (0.38s)341=== CONT TestResolveStorePath342--- PASS: TestResolveStorePath (0.00s)343=== CONT TestDoWithRetry_BodyReplayedViaGetBody344=== RUN TestSetClientTLSErrors/missing_cert_file345=== PAUSE TestSetClientTLSErrors/missing_cert_file346=== RUN TestSetClientTLSErrors/missing_key_file347=== PAUSE TestSetClientTLSErrors/missing_key_file348=== RUN TestSetClientTLSErrors/missing_ca_file349=== PAUSE TestSetClientTLSErrors/missing_ca_file350=== RUN TestSetClientTLSErrors/invalid_ca_file351=== PAUSE TestSetClientTLSErrors/invalid_ca_file352=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer353=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter354=== CONT TestEncodeNixBase32/test_string_hash355=== CONT TestEncodeNixBase32/empty_input356=== CONT TestConvertHashToNix32/SRI_format_to_Nix32357--- PASS: TestEncodeNixBase32 (0.00s)358 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)359 --- PASS: TestEncodeNixBase32/empty_input (0.00s)360=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon361=== CONT TestConvertHashToNix32/invalid_format362=== CONT TestConvertHashToNix32/already_Nix32_format363=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512364=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI365--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.27s)366=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)367=== CONT TestSupersededNARStillUploadsListing/small_NAR368--- PASS: TestConvertHashToNix32 (0.01s)369 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)370 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)371 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)372=== CONT TestSupersededNARStillUploadsListing/dump_cut_short373--- PASS: TestPathInfoHashCompatibility (0.01s)374 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)375 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)376 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)377 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.04s)378--- PASS: TestScriptTokenBadJSON (0.49s)379=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails380--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.11s)381=== CONT TestPartSizeForNAR/zero_stays_at_minimum382=== CONT TestPartSizeForNAR/capped_at_5_GiB383=== CONT TestPartSizeForNAR/5_TiB_S3_max_object384=== CONT TestPartSizeForNAR/1_TiB385=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum386=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts387=== CONT TestPartSizeForNAR/small_stays_at_minimum388=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up389--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.38s)390=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client391--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.16s)392--- PASS: TestPartSizeForNAR (0.00s)393 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)394 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)395 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)396 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)397 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)398 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)399 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)400--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.64s)401=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier402--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.30s)403=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier404=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client405--- PASS: TestScriptTokenEmptyToken (0.61s)406=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive407=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method408=== CONT TestPathInfoCACompatibility/new_structured_format_-_text409=== CONT TestPathInfoCACompatibility/old_string_format_-_text410=== CONT TestPathInfoCACompatibility/null_ca_field411=== CONT TestUploadMultipart_SupersededByPeer/missing412--- PASS: TestPathInfoCACompatibility (0.03s)413 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)414 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)415 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)416 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)417 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)418=== CONT TestUploadMultipart_SupersededByPeer/exists419--- PASS: TestDumpPathSingleFile (0.69s)420=== CONT TestParsePathInfoJSON/invalid_JSON421=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary422=== CONT TestParsePathInfoJSON/empty_input423=== CONT TestParsePathInfoJSON/whitespace_only424=== CONT TestParsePathInfoJSON/Lix_format425=== CONT TestParsePathInfoJSON/Nix_format426=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped427--- PASS: TestParsePathInfoJSON (0.02s)428 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)429 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)430 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)431 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)432 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)433=== CONT TestFilterOversizedClosures/all_closures_skipped434=== CONT TestFilterOversizedClosures/no_limit_keeps_everything435=== CONT TestGetStorePathHash/valid_store_path436--- PASS: TestFilterOversizedClosures (0.00s)437 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)438 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)439 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)440=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs441=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout442=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error443=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error444=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths445=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part446=== CONT TestGetStorePathHash/basename_without_hyphen_should_error447=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA448=== CONT TestSetClientTLS/preserves_debug_logging_transport449--- PASS: TestGetStorePathHash (0.00s)450 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)451 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)452 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)453 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)454=== CONT TestSetClientTLS/rejects_connection_without_client_cert455--- PASS: TestScriptTokenCachesUntilRefresh (0.73s)456=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths457=== CONT TestStreamPushStopsOnCancel/waiting_for_input458--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.03s)459 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.05s)460 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.09s)461 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.21s)462 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.08s)463 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.19s)464=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken465--- PASS: TestParsePathInfoJSONMultiplePaths (0.27s)466 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)467 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)468=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot469=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot470=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot471--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)472 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.11s)473 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.20s)474=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot475=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false476=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true477=== CONT TestSetClientTLSErrors/missing_cert_file478=== CONT TestSetClientTLSErrors/missing_key_file479=== CONT TestSetClientTLSErrors/missing_ca_file480=== CONT TestRateLimiterFeedback/429_enables_limiter481--- PASS: TestStreamPushBatchesUnderLoad (0.00s)482 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)483 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)484=== CONT TestSetClientTLSErrors/invalid_ca_file485=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter486=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter487=== CONT TestRateLimiterFeedback/503_enables_limiter488--- PASS: TestStreamPushStopsOnCancel (0.29s)489 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.07s)490 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.13s)491 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.06s)492 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.13s)493 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.14s)494 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.08s)495--- PASS: TestRateLimiterFeedback (0.38s)496 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.03s)497 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)498 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)499 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.06s)500--- PASS: TestDumpPathWriterError (0.88s)501--- PASS: TestSetClientTLSErrors (0.30s)502 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)503 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)504 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)505 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.11s)506--- PASS: TestSetClientTLS (0.29s)507 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.13s)508 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.23s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.29s)510--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.82s)511--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.20s)512--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.04s)513--- PASS: TestStreamPushRequestLine (1.39s)514--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (1.37s)515--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)516 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.59s)517 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.70s)518--- PASS: TestCaseHackSuffix (1.50s)519--- PASS: TestUploadMultipart_PartsInParallel (1.87s)520--- PASS: TestDumpPathMatchesNix (1.99s)521--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (2.05s)522--- PASS: TestRegisterUploadedObjectReusesConnections (1.95s)523--- PASS: TestUploadMultipart_FailedPartBufferNotReused (2.33s)524--- PASS: TestSupersededNARStillUploadsListing (0.00s)525 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.36s)526 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.25s)527 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (2.13s)528--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.09s)529 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (0.21s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.28s)531--- PASS: TestTruncatedNARDumpIsNotCompleted (3.14s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "_tribuchetbld7".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /private/var/tb/7/scratch/a5fcb26c595374a1/build/postgres4196374467/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.556557Success. You can now start the database server using:558559 pg_ctl -D /private/var/tb/7/scratch/a5fcb26c595374a1/build/postgres4196374467/data -l logfile start560561/private/var/tb/7/scratch/a5fcb26c595374a1/build/postgres4196374467:5432 - no response5622026-10-28 14:34:24.302 UTC [14873] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5632026-10-28 14:34:24.303 UTC [14873] LOG: listening on Unix socket "/private/var/tb/7/scratch/a5fcb26c595374a1/build/postgres4196374467/.s.PGSQL.5432"5642026-10-28 14:34:24.310 UTC [14880] LOG: database system was shut down at 2026-10-28 14:34:24 UTC5652026-10-28 14:34:24.312 UTC [14873] LOG: database system is ready to accept connections566/private/var/tb/7/scratch/a5fcb26c595374a1/build/postgres4196374467:5432 - accepting connections567{"timestamp":"2026-10-28T14:34:24.734732Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"84529095-6a66-4675-a945-ed378dc3fa0c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":11,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}568{"timestamp":"2026-10-28T14:34:24.845541Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ca230679-98e6-4ab8-a00b-fd166e4ead2d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}569=== RUN TestService_AuthMiddleware570=== PAUSE TestService_AuthMiddleware571=== RUN TestService_AuthMiddleware_MTLSProxyHeader572=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader573=== RUN TestService_AuthMiddleware_MTLSBoundSubjects574=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects575=== RUN TestService_ReadAuthMiddleware576=== PAUSE TestService_ReadAuthMiddleware577=== RUN TestService_AuthMiddleware_OIDC578=== PAUSE TestService_AuthMiddleware_OIDC579=== RUN TestService_RequireScope_OIDC580=== PAUSE TestService_RequireScope_OIDC581=== RUN TestService_ReadScope_PublicByDefault582=== PAUSE TestService_ReadScope_PublicByDefault583=== RUN TestCacheConfigHandler584=== PAUSE TestCacheConfigHandler585=== RUN TestCacheStatsHandler586=== PAUSE TestCacheStatsHandler587=== RUN TestClientCADerivations588=== PAUSE TestClientCADerivations589=== RUN TestClientErrorHandling590=== PAUSE TestClientErrorHandling591=== RUN TestClientIntegration592=== PAUSE TestClientIntegration593=== RUN TestClientMultipleUploads594=== PAUSE TestClientMultipleUploads595=== RUN TestClientWithDependencies596=== PAUSE TestClientWithDependencies597=== RUN TestClientSharedPathCommittedMidPush598=== PAUSE TestClientSharedPathCommittedMidPush599=== RUN TestPinProtectsFromGC600=== PAUSE TestPinProtectsFromGC601=== RUN TestClientPushesUseOnePush602=== PAUSE TestClientPushesUseOnePush603=== RUN TestClientFallsBackToClosures604=== PAUSE TestClientFallsBackToClosures605=== RUN TestDeleteClosuresRacingPins606=== PAUSE TestDeleteClosuresRacingPins607=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock609=== RUN TestResolveDBConnectionString610=== PAUSE TestResolveDBConnectionString611=== RUN TestConnectWaitsForAPeerMigration612=== PAUSE TestConnectWaitsForAPeerMigration613=== RUN TestConnectSerialisesConcurrentMigrations614=== PAUSE TestConnectSerialisesConcurrentMigrations615=== RUN TestLeadElectsOneAndHandsOver616=== PAUSE TestLeadElectsOneAndHandsOver617=== RUN TestLeadIncumbentWinsAfterRestart6182026/10/28 14:34:25 INFO lead: acquired remote=192.0.2.1:12346192026/10/28 14:34:25 INFO lead: released remote=192.0.2.1:12346202026/10/28 14:34:25 INFO lead: acquired remote=192.0.2.1:12346212026/10/28 14:34:27 INFO lead: released remote=192.0.2.1:1234622--- PASS: TestLeadIncumbentWinsAfterRestart (2.17s)623=== RUN TestLeadIncumbentAnnouncesAtOnce624=== PAUSE TestLeadIncumbentAnnouncesAtOnce625=== RUN TestLeadEndsOnShutdown626=== PAUSE TestLeadEndsOnShutdown627=== RUN TestLeadEndsWhenItsConnectionHangs6282026/10/28 14:34:27 INFO lead: acquired remote=192.0.2.1:12346292026-10-28 14:34:28.754 UTC [15760] FATAL: terminating connection due to administrator command6302026/10/28 14:34:28 INFO lead: acquired remote=192.0.2.1:12346312026/10/28 14:34:29 WARN lead: lock connection lost error="timeout: context deadline exceeded"6322026/10/28 14:34:29 INFO lead: released remote=192.0.2.1:12346332026/10/28 14:34:30 INFO lead: released remote=192.0.2.1:1234634--- PASS: TestLeadEndsWhenItsConnectionHangs (3.25s)635=== RUN TestGCAdvisoryLockBlocksConcurrentRun636=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun637=== RUN TestGCBugBareHashReferences638=== PAUSE TestGCBugBareHashReferences639=== RUN TestGCMetrics640=== PAUSE TestGCMetrics641=== RUN TestPushDedupSurvivesConcurrentGC642=== PAUSE TestPushDedupSurvivesConcurrentGC643=== RUN TestDeduplicatedObjectsRecordedAsPending644=== PAUSE TestDeduplicatedObjectsRecordedAsPending645=== RUN TestGCSweepSkipsPendingObjects646=== PAUSE TestGCSweepSkipsPendingObjects647=== RUN TestTombstonedObjectOfferedWithoutWaiting648=== PAUSE TestTombstonedObjectOfferedWithoutWaiting649=== RUN TestGCSweepDeliversEachKeyOnce650=== PAUSE TestGCSweepDeliversEachKeyOnce651=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection653=== RUN TestForceGCDuringPushOffersSweptObject654=== PAUSE TestForceGCDuringPushOffersSweptObject655=== RUN TestFailedS3DeleteKeepsTombstone656=== PAUSE TestFailedS3DeleteKeepsTombstone657=== RUN TestSweepSkipsRowsLockedByPush658=== PAUSE TestSweepSkipsRowsLockedByPush659=== RUN TestRegisterCompletedObjectNeedsPendingRow660=== PAUSE TestRegisterCompletedObjectNeedsPendingRow661=== RUN TestGetExistingObjectsLocksRows662=== PAUSE TestGetExistingObjectsLocksRows663=== RUN TestSweepRechecksPendingAfterLocking664=== PAUSE TestSweepRechecksPendingAfterLocking665=== RUN TestPushWaitsForSweepHoldingRow666=== PAUSE TestPushWaitsForSweepHoldingRow667=== RUN TestCommitRacingPendingCleanupKeepsObjects668=== PAUSE TestCommitRacingPendingCleanupKeepsObjects669=== RUN TestGCEndsOnShutdown670=== PAUSE TestGCEndsOnShutdown671=== RUN TestGCTaskStore_StartNew672=== PAUSE TestGCTaskStore_StartNew673=== RUN TestGCTaskStore_DeduplicateSameParams674=== PAUSE TestGCTaskStore_DeduplicateSameParams675=== RUN TestGCTaskStore_ConflictDifferentParams676=== PAUSE TestGCTaskStore_ConflictDifferentParams677=== RUN TestGCTaskStore_GetEmpty678=== PAUSE TestGCTaskStore_GetEmpty679=== RUN TestGCTaskStore_GetReturnsLatest680=== PAUSE TestGCTaskStore_GetReturnsLatest681=== RUN TestGCTaskStore_CompletedAllowsNewTask682=== PAUSE TestGCTaskStore_CompletedAllowsNewTask683=== RUN TestGCTaskStore_PhaseUpdates684=== PAUSE TestGCTaskStore_PhaseUpdates685=== RUN TestGCTaskStore_Fail686=== PAUSE TestGCTaskStore_Fail687=== RUN TestGracefulShutdownDrainsInflight688=== PAUSE TestGracefulShutdownDrainsInflight689=== RUN TestService_healthCheckHandler690=== PAUSE TestService_healthCheckHandler691=== RUN TestService_readinessHandler692=== PAUSE TestService_readinessHandler693=== RUN TestGenerateLandingPage694=== PAUSE TestGenerateLandingPage695=== RUN TestChildrenInheritRaisedFileLimit696=== PAUSE TestChildrenInheritRaisedFileLimit697=== RUN TestCacheConfigHandlerMaxNarSize698=== PAUSE TestCacheConfigHandlerMaxNarSize699=== RUN TestCreatePendingClosureRejectsOversizedNAR700=== PAUSE TestCreatePendingClosureRejectsOversizedNAR701=== RUN TestNARDeduplicationMetadataUploadBug702=== PAUSE TestNARDeduplicationMetadataUploadBug703=== RUN TestMetricsInventory704=== PAUSE TestMetricsInventory705=== RUN TestMetricsCommit706=== PAUSE TestMetricsCommit707=== RUN TestService_NativeMTLS708=== PAUSE TestService_NativeMTLS709=== RUN TestServerTLSConfig710=== PAUSE TestServerTLSConfig711=== RUN TestMultipartCleanup712=== PAUSE TestMultipartCleanup713=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded715=== RUN TestPendingCleanupUsesOneCutoff716=== PAUSE TestPendingCleanupUsesOneCutoff717=== RUN TestPendingClosureFailureTracksEveryUpload718=== PAUSE TestPendingClosureFailureTracksEveryUpload719=== RUN TestPendingClosureFailureAbortsItsUploads720=== PAUSE TestPendingClosureFailureAbortsItsUploads721=== RUN TestObjectStatsTrigger722=== PAUSE TestObjectStatsTrigger723=== RUN TestObjectStatsUpdatedOncePerCommit724=== PAUSE TestObjectStatsUpdatedOncePerCommit725=== RUN TestReconnectLeavesObjectsUnlocked726=== PAUSE TestReconnectLeavesObjectsUnlocked727=== RUN TestOrphanedObjectsGC728=== PAUSE TestOrphanedObjectsGC729=== RUN TestOrphanedObjectsGCStressTest730=== PAUSE TestOrphanedObjectsGCStressTest731=== RUN TestCreatePin_ReservedPins732=== PAUSE TestCreatePin_ReservedPins733=== RUN TestConcurrentPinUpdatesAgree734=== PAUSE TestConcurrentPinUpdatesAgree735=== RUN TestCreatePinRejectsBadInput736=== PAUSE TestCreatePinRejectsBadInput737=== RUN TestDeletePinKeepsRowWhenS3Fails738=== PAUSE TestDeletePinKeepsRowWhenS3Fails739=== RUN TestPresentReportsOnlyClosureRoots740=== PAUSE TestPresentReportsOnlyClosureRoots741=== RUN TestPresentRefreshesOnlyStaleClosures742=== PAUSE TestPresentRefreshesOnlyStaleClosures743=== RUN TestPresentNotReportedWhileGCDeletesClosure744=== PAUSE TestPresentNotReportedWhileGCDeletesClosure745=== RUN TestParseSingleRange746=== PAUSE TestParseSingleRange747=== RUN TestProxyHeadersOnlyTrustedOnSocket7482026/10/28 14:34:30 INFO Starting HTTP server address=proxy.sock7492026/10/28 14:34:30 INFO Starting HTTP server address=127.0.0.1:504847502026/10/28 14:34:30 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7512026/10/28 14:34:30 INFO Shutdown signal received, draining in-flight requests timeout=10s752--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.23s)753=== RUN TestIsValidCachePath754=== PAUSE TestIsValidCachePath755=== RUN TestReadProxyNarinfo756=== PAUSE TestReadProxyNarinfo757=== RUN TestReadProxyNarinfoAlreadyDecompressed758=== PAUSE TestReadProxyNarinfoAlreadyDecompressed759=== RUN TestReadProxyContentNegotiation760=== PAUSE TestReadProxyContentNegotiation761=== RUN TestReadProxyNarStreaming762=== PAUSE TestReadProxyNarStreaming763=== RUN TestReadProxy404And429764=== PAUSE TestReadProxy404And429765=== RUN TestReadProxyInvalidPath766=== PAUSE TestReadProxyInvalidPath767=== RUN TestReadProxyHead768=== PAUSE TestReadProxyHead769=== RUN TestReadProxyOutlastsServerWriteTimeout770=== PAUSE TestReadProxyOutlastsServerWriteTimeout771=== RUN TestReadProxyConditionalGet772=== PAUSE TestReadProxyConditionalGet773=== RUN TestReadProxyRootRedirectsToIndexHTML774=== PAUSE TestReadProxyRootRedirectsToIndexHTML775=== RUN TestReadProxyDisabled776=== PAUSE TestReadProxyDisabled777=== RUN TestReadRedirectNar778=== PAUSE TestReadRedirectNar779=== RUN TestReadRedirectKeepsNarinfoProxied780=== PAUSE TestReadRedirectKeepsNarinfoProxied781=== RUN TestReadProxyRangeRequest782=== PAUSE TestReadProxyRangeRequest783=== RUN TestReadRedirectUsesPublicS3URL784=== PAUSE TestReadRedirectUsesPublicS3URL785=== RUN TestPush_OverlappingRootsStoreOneRowPerKey786=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey787=== RUN TestPush_CompleteCommitsEveryRoot788=== PAUSE TestPush_CompleteCommitsEveryRoot789=== RUN TestPush_RepeatedRootCommitsOnce790=== PAUSE TestPush_RepeatedRootCommitsOnce791=== RUN TestPush_CompleteWaitsForCleanupOfThePush792=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush793=== RUN TestPush_RootsAreLockedInByteOrder794=== PAUSE TestPush_RootsAreLockedInByteOrder795=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit796=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit797=== RUN TestPush_RejectsBadRequests798=== PAUSE TestPush_RejectsBadRequests799=== RUN TestPush_SignsNarinfosOfItsPendingObjects800=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects801=== RUN TestRedundantMultipartUpload802=== PAUSE TestRedundantMultipartUpload803=== RUN TestCompleteMultipartUpload_ErrorButObjectExists804=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists805=== RUN TestCompletedNarNotReofferedAcrossClosures806=== PAUSE TestCompletedNarNotReofferedAcrossClosures807=== RUN TestPresignedUploadRegisteredBeforeCommit808=== PAUSE TestPresignedUploadRegisteredBeforeCommit809=== RUN TestService_Rustfstest810=== PAUSE TestService_Rustfstest811=== RUN TestParseSize812=== PAUSE TestParseSize813=== RUN TestSkippedUploadsHandler814=== PAUSE TestSkippedUploadsHandler815=== RUN TestSystemdListenerNotActivated816--- PASS: TestSystemdListenerNotActivated (0.00s)817=== RUN TestWatchdogBeatsWhenHealthy818--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)819=== RUN TestWatchdogSkipsWhenUnhealthy8202026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/28 14:34:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"830--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)831=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle833=== RUN TestProxyWriteTimeout834=== PAUSE TestProxyWriteTimeout835=== RUN TestPendingClosureWriteTimeout836=== PAUSE TestPendingClosureWriteTimeout837=== RUN TestIsValidUploadKey838=== PAUSE TestIsValidUploadKey839=== RUN TestUploadHandlersRejectInvalidKeys840=== PAUSE TestUploadHandlersRejectInvalidKeys841=== RUN TestUploadHandlersRejectOversizedBody842=== PAUSE TestUploadHandlersRejectOversizedBody843=== RUN TestService_cleanupPendingClosuresHandler844=== PAUSE TestService_cleanupPendingClosuresHandler845=== RUN TestService_createPendingClosureHandler846=== PAUSE TestService_createPendingClosureHandler847=== RUN TestService_verifyS3Integrity848=== PAUSE TestService_verifyS3Integrity849=== RUN TestCompleteMultipartUnregistered850=== PAUSE TestCompleteMultipartUnregistered851=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT852=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT853=== CONT TestReadProxyNarinfoAlreadyDecompressed854=== CONT TestSweepRechecksPendingAfterLocking855=== CONT TestPresentNotReportedWhileGCDeletesClosure856=== CONT TestClientWithDependencies857=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale858=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale859=== CONT TestPresentRefreshesOnlyStaleClosures860=== CONT TestService_ReadScope_PublicByDefault861=== CONT TestService_AuthMiddleware862=== CONT TestClientSharedPathCommittedMidPush863=== CONT TestClientCADerivations864=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh865=== CONT TestPushWaitsForSweepHoldingRow866=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock867=== CONT TestDeleteClosuresRacingPins868=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh869=== CONT TestCompleteMultipartUnregistered870=== CONT TestResolveDBConnectionString871=== CONT TestClientFallsBackToClosures872=== CONT TestParseSingleRange873=== CONT TestIsValidCachePath874=== CONT TestClientPushesUseOnePush875=== RUN TestIsValidCachePath/narinfo876=== CONT TestPinProtectsFromGC877=== CONT TestClientMultipleUploads878=== PAUSE TestIsValidCachePath/narinfo879=== CONT TestClientIntegration880=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit881=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT882=== CONT TestConnectSerialisesConcurrentMigrations883=== CONT TestReadProxyNarinfo884=== RUN TestParseSingleRange/none885=== RUN TestResolveDBConnectionString/flag_wins886=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars887=== PAUSE TestParseSingleRange/none888=== PAUSE TestResolveDBConnectionString/flag_wins889=== RUN TestParseSingleRange/unknown_unit890=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars891=== PAUSE TestParseSingleRange/unknown_unit892=== RUN TestParseSingleRange/multi-range_ignored893=== RUN TestIsValidCachePath/nar_zst894=== RUN TestResolveDBConnectionString/file_when_flag_empty895=== PAUSE TestParseSingleRange/multi-range_ignored896=== PAUSE TestResolveDBConnectionString/file_when_flag_empty897=== RUN TestResolveDBConnectionString/missing_file_is_an_error898=== RUN TestParseSingleRange/malformed_no_dash899=== PAUSE TestIsValidCachePath/nar_zst900=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error901=== PAUSE TestParseSingleRange/malformed_no_dash902=== RUN TestIsValidCachePath/nar_xz903=== RUN TestResolveDBConnectionString/PGHOST_allows_empty904=== PAUSE TestIsValidCachePath/nar_xz905=== RUN TestParseSingleRange/malformed_both_empty906=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty907=== PAUSE TestParseSingleRange/malformed_both_empty908=== RUN TestIsValidCachePath/nar_bz2909=== RUN TestResolveDBConnectionString/nothing_configured910=== PAUSE TestIsValidCachePath/nar_bz2911=== PAUSE TestResolveDBConnectionString/nothing_configured912=== CONT TestService_createPendingClosureHandler913=== RUN TestIsValidCachePath/nar_uncompressed914=== PAUSE TestIsValidCachePath/nar_uncompressed915=== RUN TestIsValidCachePath/ls916=== PAUSE TestIsValidCachePath/ls917=== RUN TestIsValidCachePath/log918=== PAUSE TestIsValidCachePath/log919=== RUN TestIsValidCachePath/realisation920=== PAUSE TestIsValidCachePath/realisation921=== RUN TestIsValidCachePath/nix-cache-info922=== PAUSE TestIsValidCachePath/nix-cache-info923=== RUN TestIsValidCachePath/index.html924=== RUN TestParseSingleRange/malformed_end_before_start925=== PAUSE TestIsValidCachePath/index.html926=== RUN TestIsValidCachePath/traversal_parent927=== PAUSE TestIsValidCachePath/traversal_parent928=== RUN TestIsValidCachePath/traversal_in_middle929=== PAUSE TestIsValidCachePath/traversal_in_middle930=== RUN TestIsValidCachePath/invalid_char_e931=== PAUSE TestParseSingleRange/malformed_end_before_start932=== PAUSE TestIsValidCachePath/invalid_char_e933=== RUN TestIsValidCachePath/invalid_char_u934=== RUN TestParseSingleRange/closed935=== PAUSE TestParseSingleRange/closed936=== PAUSE TestIsValidCachePath/invalid_char_u937=== RUN TestIsValidCachePath/random_path938=== PAUSE TestIsValidCachePath/random_path939=== RUN TestParseSingleRange/open-ended940=== RUN TestIsValidCachePath/empty941=== PAUSE TestIsValidCachePath/empty942=== RUN TestIsValidCachePath/leading_slash943=== PAUSE TestIsValidCachePath/leading_slash944=== RUN TestIsValidCachePath/wrong_extension945=== PAUSE TestIsValidCachePath/wrong_extension946=== RUN TestIsValidCachePath/short_hash947=== PAUSE TestParseSingleRange/open-ended948=== RUN TestParseSingleRange/end_clamped_to_size949=== PAUSE TestParseSingleRange/end_clamped_to_size950=== RUN TestParseSingleRange/suffix951=== PAUSE TestParseSingleRange/suffix952=== RUN TestParseSingleRange/suffix_exceeds_size953=== PAUSE TestParseSingleRange/suffix_exceeds_size954=== RUN TestParseSingleRange/single_byte955=== PAUSE TestIsValidCachePath/short_hash956=== PAUSE TestParseSingleRange/single_byte957=== CONT TestService_cleanupPendingClosuresHandler958=== RUN TestParseSingleRange/start_past_EOF959=== PAUSE TestParseSingleRange/start_past_EOF960=== RUN TestParseSingleRange/start_far_past_EOF961=== PAUSE TestParseSingleRange/start_far_past_EOF962=== CONT TestUploadHandlersRejectOversizedBody963=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure964=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure965=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart966=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart967=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts968=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts969=== CONT TestService_verifyS3Integrity9702026-10-28 14:34:32.628 UTC [17391] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"9712026-10-28 14:34:32.628 UTC [17391] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.9722026-10-28 14:34:32.628 UTC [17391] STATEMENT: CREATE TABLE goose_db_version (973 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,974 version_id bigint NOT NULL,975 is_applied boolean NOT NULL,976 tstamp timestamp NOT NULL DEFAULT now()977 )978--- PASS: TestPresentRefreshesOnlyStaleClosures (2.48s)979=== CONT TestIsValidUploadKey980=== RUN TestIsValidUploadKey/narinfo981=== PAUSE TestIsValidUploadKey/narinfo982=== RUN TestIsValidUploadKey/nar_zst983=== PAUSE TestIsValidUploadKey/nar_zst984=== RUN TestIsValidUploadKey/nar_xz985=== PAUSE TestIsValidUploadKey/nar_xz986=== RUN TestIsValidUploadKey/nar_plain987=== PAUSE TestIsValidUploadKey/nar_plain988=== RUN TestIsValidUploadKey/listing989=== PAUSE TestIsValidUploadKey/listing990=== RUN TestIsValidUploadKey/build_log991=== PAUSE TestIsValidUploadKey/build_log992=== RUN TestIsValidUploadKey/build_log_home-manager_file993=== PAUSE TestIsValidUploadKey/build_log_home-manager_file994=== RUN TestIsValidUploadKey/build_log_plus_in_name995=== PAUSE TestIsValidUploadKey/build_log_plus_in_name996=== RUN TestIsValidUploadKey/build_log_question_mark997=== PAUSE TestIsValidUploadKey/build_log_question_mark998=== RUN TestIsValidUploadKey/build_log_equals999=== PAUSE TestIsValidUploadKey/build_log_equals1000=== RUN TestIsValidUploadKey/realisation1001=== PAUSE TestIsValidUploadKey/realisation1002=== RUN TestIsValidUploadKey/realisation_plus_in_output1003=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1004=== RUN TestIsValidUploadKey/nix-cache-info1005=== PAUSE TestIsValidUploadKey/nix-cache-info1006=== RUN TestIsValidUploadKey/index.html1007=== PAUSE TestIsValidUploadKey/index.html1008=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1009=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1010=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1011=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1012=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1013=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1014=== RUN TestIsValidUploadKey/traversal1015=== PAUSE TestIsValidUploadKey/traversal1016=== RUN TestIsValidUploadKey/traversal_nar1017=== PAUSE TestIsValidUploadKey/traversal_nar1018=== RUN TestIsValidUploadKey/absolute1019=== PAUSE TestIsValidUploadKey/absolute1020=== RUN TestIsValidUploadKey/empty_key1021=== PAUSE TestIsValidUploadKey/empty_key1022=== RUN TestIsValidUploadKey/unknown_type1023=== PAUSE TestIsValidUploadKey/unknown_type1024=== CONT TestPendingClosureWriteTimeout1025=== RUN TestPendingClosureWriteTimeout/empty1026=== PAUSE TestPendingClosureWriteTimeout/empty1027=== RUN TestPendingClosureWriteTimeout/400_objects1028=== PAUSE TestPendingClosureWriteTimeout/400_objects1029=== RUN TestPendingClosureWriteTimeout/670k_objects1030=== PAUSE TestPendingClosureWriteTimeout/670k_objects1031=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1032=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1033=== CONT TestUploadHandlersRejectInvalidKeys1034=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1035=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1036=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1037=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1038=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1039=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1040=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1041=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1042=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10432026/10/28 14:34:33 INFO Received cleanup request method=DELETE path=/api/pending_closures10442026/10/28 14:34:33 INFO Aborted multipart uploads count=0 kept=010452026/10/28 14:34:33 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestConnectSerialisesConcurrentMigrations (2.96s)1047=== CONT TestProxyWriteTimeout1048=== RUN TestProxyWriteTimeout/narinfo1049=== PAUSE TestProxyWriteTimeout/narinfo1050=== RUN TestProxyWriteTimeout/1_GiB_nar1051=== PAUSE TestProxyWriteTimeout/1_GiB_nar1052=== RUN TestProxyWriteTimeout/10_GiB_nar1053=== PAUSE TestProxyWriteTimeout/10_GiB_nar1054=== RUN TestProxyWriteTimeout/unknown_size1055=== PAUSE TestProxyWriteTimeout/unknown_size1056=== CONT TestParseSize1057--- PASS: TestParseSize (0.00s)1058=== CONT TestService_Rustfstest10592026/10/28 14:34:33 INFO Received cleanup request method=DELETE path=/api/pending_closures10602026/10/28 14:34:34 INFO Aborted multipart uploads count=1 kept=010612026/10/28 14:34:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10622026-10-28 14:34:34.026 UTC [17215] ERROR: Closure does not exist: id=110632026-10-28 14:34:34.026 UTC [17215] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10642026-10-28 14:34:34.026 UTC [17215] STATEMENT: -- name: CommitPendingClosure :one1065 SELECT commit_pending_closure($1::bigint)::bigint1066 1067--- PASS: TestService_cleanupPendingClosuresHandler (3.33s)1068=== CONT TestSkippedUploadsHandler10692026/10/28 14:34:34 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001070--- PASS: TestSkippedUploadsHandler (0.01s)1071=== CONT TestCompletedNarNotReofferedAcrossClosures1072--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.64s)1073=== CONT TestPresignedUploadRegisteredBeforeCommit10742026/10/28 14:34:35 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/28 14:34:35 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1076=== NAME TestClientCADerivations1077 client_ca_test.go:136: Built CA derivation: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientCADerivations997235551/001/store/lg95i8cvkginf7zj91bshf6zw1rknzxk-ca-test1078--- PASS: TestService_AuthMiddleware (4.89s)1079=== CONT TestRedundantMultipartUpload1080--- PASS: TestPushWaitsForSweepHoldingRow (5.07s)1081=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1082=== NAME TestClientCADerivations1083 client_ca_test.go:139: Found 1 dependencies (including self)1084--- PASS: TestService_ReadScope_PublicByDefault (5.55s)1085=== CONT TestPush_RejectsBadRequests10862026/10/28 14:34:36 INFO Received push request method=POST path=/api/pushes10872026/10/28 14:34:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10882026/10/28 14:34:36 INFO Uploading lg95i8cvkginf7zj91bshf6zw1rknzxk-ca-test (144B)10892026/10/28 14:34:36 WARN Failed to register uploaded object key=lg95i8cvkginf7zj91bshf6zw1rknzxk.ls error="server returned 404: 404 page not found\n"10902026/10/28 14:34:36 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10912026/10/28 14:34:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10922026/10/28 14:34:37 WARN Failed to register uploaded object key=log/gmzrlsc5xc6p8inrwha7nky8pmwmgzy7-ca-test.drv error="server returned 404: 404 page not found\n"10932026/10/28 14:34:37 INFO Signed narinfos id=1 count=110942026/10/28 14:34:37 INFO Uploading 1 narinfos10952026/10/28 14:34:37 WARN Failed to register uploaded object key=lg95i8cvkginf7zj91bshf6zw1rknzxk.narinfo error="server returned 404: 404 page not found\n"10962026/10/28 14:34:37 INFO Received complete push request method=POST path=/api/pushes/1/complete10972026/10/28 14:34:37 INFO Completed push id=1 objects=4 duration=16.394708ms10982026/10/28 14:34:37 INFO Upload complete. (989ms)1099=== NAME TestClientCADerivations1100 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientCADerivations997235551/001/store/lg95i8cvkginf7zj91bshf6zw1rknzxk-ca-test1101 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1102 Compression: zstd1103 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1104 NarSize: 1441105 References: 1106 Deriver: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientCADerivations997235551/001/store/gmzrlsc5xc6p8inrwha7nky8pmwmgzy7-ca-test.drv1107 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1108 client_ca_test.go:185: Checking for realisation files in S3...1109 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1110 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1111 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket7?endpoint=http://localhost:50455®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientCADerivations997235551/001/store'1112 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11113--- PASS: TestClientCADerivations (6.95s)1114=== CONT TestDeduplicatedObjectsRecordedAsPending11152026/10/28 14:34:38 INFO Received push request method=POST path=/api/pushes1116=== NAME TestClientWithDependencies1117 client_integration_test.go:722: Built derivation: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientWithDependencies1100626929/001/store/l85ixv64h76b4w98mziij32y40341j0s-test-script1118 client_integration_test.go:724: Found 1 dependencies (including self)1119=== NAME TestClientMultipleUploads1120 client_integration_test.go:467: Created store path 0: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientMultipleUploads2718224480/001/store/6bmi12hp9p1zd314dymgd90amd22aa1n-test-file-0.txt11212026/10/28 14:34:39 INFO Received push request method=POST path=/api/pushes11222026/10/28 14:34:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11232026/10/28 14:34:39 INFO Uploading l85ixv64h76b4w98mziij32y40341j0s-test-script (136B)11242026/10/28 14:34:39 WARN Failed to register uploaded object key=l85ixv64h76b4w98mziij32y40341j0s.ls error="server returned 404: 404 page not found\n"11252026/10/28 14:34:40 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11262026/10/28 14:34:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11272026/10/28 14:34:40 WARN Failed to register uploaded object key=log/pcnr44771s36cgm874yn563z75qdvzrx-test-script.drv error="server returned 404: 404 page not found\n"11282026/10/28 14:34:40 INFO Signed narinfos id=1 count=111292026/10/28 14:34:40 INFO Uploading 1 narinfos1130 client_integration_test.go:467: Created store path 1: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientMultipleUploads2718224480/001/store/0y21m1i0vx1k425086nhajni1gragq3f-test-file-1.txt11312026/10/28 14:34:40 INFO Received complete push request method=POST path=/api/pushes/1/complete11322026/10/28 14:34:40 WARN Failed to register uploaded object key=l85ixv64h76b4w98mziij32y40341j0s.narinfo error="server returned 404: 404 page not found\n"11332026/10/28 14:34:40 INFO Completed push id=1 objects=4 duration=33.444833ms11342026/10/28 14:34:40 INFO Upload complete. (927ms)11352026/10/28 14:34:40 INFO Aborted multipart uploads count=0 kept=01136 client_integration_test.go:467: Created store path 2: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientMultipleUploads2718224480/001/store/3n5230kxdfdz47izd99kypm47wbxzkrs-test-file-2.txt11372026/10/28 14:34:40 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/10/28 14:34:40 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=011392026/10/28 14:34:40 INFO Vacuumed table table=pending_closures11402026/10/28 14:34:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11412026/10/28 14:34:40 INFO Vacuumed table table=pending_objects11422026/10/28 14:34:40 INFO Vacuumed table table=multipart_uploads11432026/10/28 14:34:40 INFO Vacuumed table table=closures11442026/10/28 14:34:40 INFO Vacuumed table table=objects11452026/10/28 14:34:40 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1146=== NAME TestClientWithDependencies1147 client_integration_test.go:740: Skipping nix copy test - isolated store (/private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientWithDependencies1100626929/001/store) requires matching store prefix1148--- PASS: TestCompleteMultipartUnregistered (10.40s)1149=== CONT TestGCEndsOnShutdown1150=== RUN TestGCEndsOnShutdown/before_the_run1151=== PAUSE TestGCEndsOnShutdown/before_the_run1152=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1153=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1154=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1155=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1156=== CONT TestRegisterCompletedObjectNeedsPendingRow1157--- PASS: TestClientWithDependencies (10.47s)1158=== CONT TestSweepSkipsRowsLockedByPush11592026/10/28 14:34:42 INFO Received push request method=POST path=/api/pushes1160--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (11.37s)1161=== CONT TestGetExistingObjectsLocksRows11622026/10/28 14:34:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11632026/10/28 14:34:42 INFO Uploading 6bmi12hp9p1zd314dymgd90amd22aa1n-test-file-0.txt (160B)11642026/10/28 14:34:42 INFO Uploading 3n5230kxdfdz47izd99kypm47wbxzkrs-test-file-2.txt (160B)11652026/10/28 14:34:42 INFO Uploading 0y21m1i0vx1k425086nhajni1gragq3f-test-file-1.txt (160B)11662026/10/28 14:34:42 WARN Failed to register uploaded object key=0y21m1i0vx1k425086nhajni1gragq3f.ls error="server returned 404: 404 page not found\n"11672026/10/28 14:34:42 WARN Failed to register uploaded object key=3n5230kxdfdz47izd99kypm47wbxzkrs.ls error="server returned 404: 404 page not found\n"11682026/10/28 14:34:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11692026/10/28 14:34:42 WARN Failed to register uploaded object key=6bmi12hp9p1zd314dymgd90amd22aa1n.ls error="server returned 404: 404 page not found\n"11702026/10/28 14:34:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11712026/10/28 14:34:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11722026/10/28 14:34:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11732026/10/28 14:34:42 INFO Signed narinfos id=1 count=311742026/10/28 14:34:42 INFO Uploading 3 narinfos1175=== NAME TestClientIntegration1176 client_integration_test.go:331: Created store path: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientIntegration3217315904/002/store/6xvplsl61cb5pp50kcawsn2nzlifv3g8-test-file.txt11772026/10/28 14:34:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11782026/10/28 14:34:42 WARN Failed to register uploaded object key=3n5230kxdfdz47izd99kypm47wbxzkrs.narinfo error="server returned 404: 404 page not found\n"11792026/10/28 14:34:42 WARN Failed to register uploaded object key=0y21m1i0vx1k425086nhajni1gragq3f.narinfo error="server returned 404: 404 page not found\n"11802026/10/28 14:34:42 WARN Failed to register uploaded object key=6bmi12hp9p1zd314dymgd90amd22aa1n.narinfo error="server returned 404: 404 page not found\n"11812026/10/28 14:34:42 INFO Completed push id=1 objects=9 duration=54.457833ms11822026/10/28 14:34:42 INFO Upload complete. (1.478s)1183=== NAME TestClientMultipleUploads1184 client_integration_test.go:478: Uploaded 3 paths in 2.570773667s11852026/10/28 14:34:43 INFO Received push request method=POST path=/api/pushes1186--- PASS: TestClientMultipleUploads (12.84s)1187=== CONT TestFailedS3DeleteKeepsTombstone11882026/10/28 14:34:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11892026/10/28 14:34:43 INFO Uploading 6xvplsl61cb5pp50kcawsn2nzlifv3g8-test-file.txt (152B)11902026/10/28 14:34:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11912026/10/28 14:34:44 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/28 14:34:44 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/28 14:34:44 INFO Received uploads request method=POST path=/api/pending_closures11942026/10/28 14:34:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11952026/10/28 14:34:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11962026/10/28 14:34:44 WARN Failed to register uploaded object key=6xvplsl61cb5pp50kcawsn2nzlifv3g8.ls error="server returned 404: 404 page not found\n"11972026/10/28 14:34:44 INFO Signed narinfos id=1 count=111982026/10/28 14:34:44 INFO Uploading 1 narinfos11992026/10/28 14:34:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12002026/10/28 14:34:44 WARN Failed to register uploaded object key=6xvplsl61cb5pp50kcawsn2nzlifv3g8.narinfo error="server returned 404: 404 page not found\n"12012026/10/28 14:34:44 INFO Completed push id=1 objects=3 duration=74.861042ms12022026/10/28 14:34:44 INFO Upload complete. (1.387s)12032026/10/28 14:34:44 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjk4OTgzOGRhLWRkNTYtNDBmNC1iZGE5LTg3YzNhZjRiZDEzY3gxNzkzMTk4MDc4MTkzNzI2MDAw parts=1012042026/10/28 14:34:45 INFO All 1 paths already cached1205=== NAME TestClientIntegration1206 client_integration_test.go:357: Retrieved narinfo from S3:1207 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientIntegration3217315904/002/store/6xvplsl61cb5pp50kcawsn2nzlifv3g8-test-file.txt1208 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1209 Compression: zstd1210 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11211 NarSize: 1521212 References: 1213 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11214 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1215 client_integration_test.go:358: Decompressed .ls content (64 bytes):1216 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}12172026/10/28 14:34:46 INFO Received uploads request method=POST path=/api/pending_closures12182026/10/28 14:34:46 INFO Received uploads request method=POST path=/api/pending_closures12192026/10/28 14:34:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12202026/10/28 14:34:47 INFO Uploading k82li20yvkx040h3nki3f6qqsz2jc2vp-a (256B)12212026/10/28 14:34:47 INFO Uploading 6gvhargkb9mrf6qfzih7hnii5sgnxjmv-shared-dep (136B)12222026/10/28 14:34:47 WARN Failed to register uploaded object key=3pmv125vjlfcrkx27b6c75llx1w6vwkm.ls error="server returned 404: 404 page not found\n"12232026/10/28 14:34:47 WARN Failed to register uploaded object key=nar/1q4x5m6f8ilh01zcpphi24c368sadxyf92hr3a2nz1ql43c30g98.nar.zst error="server returned 404: 404 page not found\n"12242026/10/28 14:34:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12252026/10/28 14:34:47 WARN Failed to register uploaded object key=6gvhargkb9mrf6qfzih7hnii5sgnxjmv.ls error="server returned 404: 404 page not found\n"12262026/10/28 14:34:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12272026/10/28 14:34:47 INFO Signed narinfos id=1 count=212282026/10/28 14:34:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12292026/10/28 14:34:47 INFO Signed narinfos id=2 count=212302026/10/28 14:34:47 INFO Uploading 4 narinfos12312026/10/28 14:34:47 WARN Failed to register uploaded object key=k82li20yvkx040h3nki3f6qqsz2jc2vp.ls error="server returned 404: 404 page not found\n"12322026/10/28 14:34:47 INFO Received push request method=POST path=/api/pushes12332026/10/28 14:34:47 INFO Received push request method=POST path=/api/pushes12342026/10/28 14:34:47 INFO Aborted multipart uploads count=0 kept=012352026/10/28 14:34:47 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12362026/10/28 14:34:47 INFO Uploading fdgi9wav8v2yxn41q0zf79xg8n0hrkpc-top (264B)12372026/10/28 14:34:47 INFO Uploading 8zdjrk7vqm4aq7xpyry17iwlxfysa9yw-shared-dep (136B)12382026/10/28 14:34:47 WARN Failed to register uploaded object key=6gvhargkb9mrf6qfzih7hnii5sgnxjmv.narinfo error="server returned 404: 404 page not found\n"12392026/10/28 14:34:47 INFO Object in database but missing from S3 key=6xvplsl61cb5pp50kcawsn2nzlifv3g8.ls12402026/10/28 14:34:47 WARN Found objects in DB but missing from S3, will re-upload count=112412026/10/28 14:34:47 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12422026/10/28 14:34:47 WARN Failed to register uploaded object key=3pmv125vjlfcrkx27b6c75llx1w6vwkm.narinfo error="server returned 404: 404 page not found\n"12432026/10/28 14:34:47 WARN Failed to register uploaded object key=k82li20yvkx040h3nki3f6qqsz2jc2vp.narinfo error="server returned 404: 404 page not found\n"12442026/10/28 14:34:47 WARN Force mode enabled - objects will be deleted immediately without grace period12452026/10/28 14:34:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12462026/10/28 14:34:47 WARN Failed to register uploaded object key=6gvhargkb9mrf6qfzih7hnii5sgnxjmv.narinfo error="server returned 404: 404 page not found\n"12472026/10/28 14:34:47 INFO Completed upload id=1 objects=6 duration=35.769667ms12482026/10/28 14:34:47 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12492026/10/28 14:34:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12502026/10/28 14:34:47 INFO Completed upload id=2 objects=6 duration=8.14ms12512026/10/28 14:34:47 WARN Failed to register uploaded object key=8zdjrk7vqm4aq7xpyry17iwlxfysa9yw.ls error="server returned 404: 404 page not found\n"12522026/10/28 14:34:47 INFO Upload complete. (1.862s)12532026/10/28 14:34:47 INFO Received complete push request method=POST path=/api/pushes/2/complete12542026/10/28 14:34:47 WARN Failed to register uploaded object key=fdgi9wav8v2yxn41q0zf79xg8n0hrkpc.ls error="server returned 404: 404 page not found\n"1255=== NAME TestClientFallsBackToClosures1256 client_pushes_test.go:112: Retrieved narinfo from S3:1257 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientFallsBackToClosures3625501558/001/store/6gvhargkb9mrf6qfzih7hnii5sgnxjmv-shared-dep1258 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1259 Compression: zstd1260 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821261 NarSize: 1361262 References: 1263 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12642026/10/28 14:34:47 INFO Completed push id=2 objects=3 duration=30.181209ms12652026/10/28 14:34:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12662026/10/28 14:34:47 INFO Upload complete. (920ms)12672026/10/28 14:34:47 WARN Failed to register uploaded object key=6xvplsl61cb5pp50kcawsn2nzlifv3g8.ls error="server returned 404: 404 page not found\n"12682026/10/28 14:34:47 INFO Signed narinfos id=1 count=212692026/10/28 14:34:47 WARN Failed to register uploaded object key=nar/0nyj0z5l98rc9z6bvcmrpkjj7yph8va74rv8hff04avlb5y8rcvp.nar.zst error="server returned 404: 404 page not found\n"12702026/10/28 14:34:47 INFO Uploading 2 narinfos12712026/10/28 14:34:47 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=01272=== NAME TestClientIntegration1273 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1274 client_integration_test.go:375: Decompressed .ls content (49 bytes):1275 {"version":1,"root":{"type":"regular","size":39}}1276=== NAME TestClientFallsBackToClosures1277 client_pushes_test.go:112: Retrieved narinfo from S3:1278 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientFallsBackToClosures3625501558/001/store/k82li20yvkx040h3nki3f6qqsz2jc2vp-a1279 URL: nar/1q4x5m6f8ilh01zcpphi24c368sadxyf92hr3a2nz1ql43c30g98.nar.zst1280 Compression: zstd1281 NarHash: sha256:1q4x5m6f8ilh01zcpphi24c368sadxyf92hr3a2nz1ql43c30g981282 NarSize: 2561283 References: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientFallsBackToClosures3625501558/001/store/6gvhargkb9mrf6qfzih7hnii5sgnxjmv-shared-dep1284 CA: text:sha256:0q011x2gv5iy68ridx4mgkh029ycv326yn5y2kdbkdgv0nivnp7b12852026/10/28 14:34:47 INFO Vacuumed table table=pending_closures12862026/10/28 14:34:47 INFO Vacuumed table table=pending_objects1287 client_pushes_test.go:112: Retrieved narinfo from S3:1288 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientFallsBackToClosures3625501558/001/store/3pmv125vjlfcrkx27b6c75llx1w6vwkm-b1289 URL: nar/1q4x5m6f8ilh01zcpphi24c368sadxyf92hr3a2nz1ql43c30g98.nar.zst1290 Compression: zstd1291 NarHash: sha256:1q4x5m6f8ilh01zcpphi24c368sadxyf92hr3a2nz1ql43c30g981292 NarSize: 2561293 References: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientFallsBackToClosures3625501558/001/store/6gvhargkb9mrf6qfzih7hnii5sgnxjmv-shared-dep1294 CA: text:sha256:0q011x2gv5iy68ridx4mgkh029ycv326yn5y2kdbkdgv0nivnp7b12952026/10/28 14:34:47 INFO Vacuumed table table=multipart_uploads12962026/10/28 14:34:47 INFO Vacuumed table table=closures12972026/10/28 14:34:48 INFO Vacuumed table table=objects12982026/10/28 14:34:48 WARN Failed to register uploaded object key=fdgi9wav8v2yxn41q0zf79xg8n0hrkpc.narinfo error="server returned 404: 404 page not found\n"12992026/10/28 14:34:48 INFO Received complete push request method=POST path=/api/pushes/1/complete13002026/10/28 14:34:48 WARN Failed to register uploaded object key=8zdjrk7vqm4aq7xpyry17iwlxfysa9yw.narinfo error="server returned 404: 404 page not found\n"13012026/10/28 14:34:48 INFO Completed push id=1 objects=6 duration=54.363125ms13022026/10/28 14:34:48 INFO Upload complete. (1.229s)1303=== NAME TestClientSharedPathCommittedMidPush1304 client_integration_test.go:803: Retrieved narinfo from S3:1305 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientSharedPathCommittedMidPush1350846498/001/store/8zdjrk7vqm4aq7xpyry17iwlxfysa9yw-shared-dep1306 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1307 Compression: zstd1308 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821309 NarSize: 1361310 References: 1311 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1312 client_integration_test.go:803: Retrieved narinfo from S3:1313 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientSharedPathCommittedMidPush1350846498/001/store/fdgi9wav8v2yxn41q0zf79xg8n0hrkpc-top1314 URL: nar/0nyj0z5l98rc9z6bvcmrpkjj7yph8va74rv8hff04avlb5y8rcvp.nar.zst1315 Compression: zstd1316 NarHash: sha256:0nyj0z5l98rc9z6bvcmrpkjj7yph8va74rv8hff04avlb5y8rcvp1317 NarSize: 2641318 References: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientSharedPathCommittedMidPush1350846498/001/store/8zdjrk7vqm4aq7xpyry17iwlxfysa9yw-shared-dep1319 CA: text:sha256:0kj5z4jpmd003skvddyjfljhmidvkwgkhfcr7ij1svcvihgj7m5k1320--- PASS: TestSweepRechecksPendingAfterLocking (17.51s)1321=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1322--- PASS: TestClientFallsBackToClosures (17.67s)1323=== CONT TestGCSweepDeliversEachKeyOnce1324--- PASS: TestClientSharedPathCommittedMidPush (17.79s)1325=== CONT TestTombstonedObjectOfferedWithoutWaiting13262026/10/28 14:34:49 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/28 14:34:49 INFO Received push request method=POST path=/api/pushes13282026/10/28 14:34:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13292026/10/28 14:34:49 INFO Uploading lvr5slsqjb643qsmjgqbs6yymzmr3hyn-shared-dep (136B)13302026/10/28 14:34:49 INFO Uploading d6h7cm5l17kn4s72hhms8ymyjrsb47ky-a (256B)1331--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (18.99s)1332=== CONT TestGCSweepSkipsPendingObjects13332026/10/28 14:34:50 WARN Failed to register uploaded object key=d6h7cm5l17kn4s72hhms8ymyjrsb47ky.ls error="server returned 404: 404 page not found\n"13342026/10/28 14:34:50 WARN Failed to register uploaded object key=lvr5slsqjb643qsmjgqbs6yymzmr3hyn.ls error="server returned 404: 404 page not found\n"13352026/10/28 14:34:50 WARN Failed to register uploaded object key=74pfxp19w1bfsafshx0qyjvqq4klpwpx.ls error="server returned 404: 404 page not found\n"13362026/10/28 14:34:50 WARN Failed to register uploaded object key=nar/07690b9q2r18f1wlbd19vsql64ki73q918xpic9aa2fwh16241v7.nar.zst error="server returned 404: 404 page not found\n"13372026/10/28 14:34:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13382026/10/28 14:34:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13392026/10/28 14:34:50 INFO Signed narinfos id=1 count=313402026/10/28 14:34:50 INFO Uploading 3 narinfos13412026/10/28 14:34:50 WARN Failed to register uploaded object key=74pfxp19w1bfsafshx0qyjvqq4klpwpx.narinfo error="server returned 404: 404 page not found\n"13422026/10/28 14:34:50 WARN Failed to register uploaded object key=d6h7cm5l17kn4s72hhms8ymyjrsb47ky.narinfo error="server returned 404: 404 page not found\n"13432026/10/28 14:34:50 INFO Received complete push request method=POST path=/api/pushes/1/complete13442026/10/28 14:34:50 WARN Failed to register uploaded object key=lvr5slsqjb643qsmjgqbs6yymzmr3hyn.narinfo error="server returned 404: 404 page not found\n"13452026/10/28 14:34:50 INFO Received push request method=POST path=/api/pushes13462026/10/28 14:34:50 INFO Completed push id=1 objects=8 duration=83.460833ms13472026/10/28 14:34:50 INFO Upload complete. (1.723s)1348=== NAME TestClientPushesUseOnePush1349 client_pushes_test.go:97: Retrieved narinfo from S3:1350 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientPushesUseOnePush489859837/001/store/lvr5slsqjb643qsmjgqbs6yymzmr3hyn-shared-dep1351 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1352 Compression: zstd1353 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821354 NarSize: 1361355 References: 1356 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13572026/10/28 14:34:50 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1358 client_pushes_test.go:97: Retrieved narinfo from S3:1359 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientPushesUseOnePush489859837/001/store/d6h7cm5l17kn4s72hhms8ymyjrsb47ky-a1360 URL: nar/07690b9q2r18f1wlbd19vsql64ki73q918xpic9aa2fwh16241v7.nar.zst1361 Compression: zstd1362 NarHash: sha256:07690b9q2r18f1wlbd19vsql64ki73q918xpic9aa2fwh16241v71363 NarSize: 2561364 References: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientPushesUseOnePush489859837/001/store/lvr5slsqjb643qsmjgqbs6yymzmr3hyn-shared-dep1365 CA: text:sha256:1nhc7qa9mdc1h3s698gdd85pfms65ixhlr5bzkzkqdb48r5wdqw81366 client_pushes_test.go:97: Retrieved narinfo from S3:1367 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientPushesUseOnePush489859837/001/store/74pfxp19w1bfsafshx0qyjvqq4klpwpx-b1368 URL: nar/07690b9q2r18f1wlbd19vsql64ki73q918xpic9aa2fwh16241v7.nar.zst1369 Compression: zstd1370 NarHash: sha256:07690b9q2r18f1wlbd19vsql64ki73q918xpic9aa2fwh16241v71371 NarSize: 2561372 References: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientPushesUseOnePush489859837/001/store/lvr5slsqjb643qsmjgqbs6yymzmr3hyn-shared-dep1373 CA: text:sha256:1nhc7qa9mdc1h3s698gdd85pfms65ixhlr5bzkzkqdb48r5wdqw813742026/10/28 14:34:51 INFO Received complete push request method=POST path=/api/pushes/3/complete13752026/10/28 14:34:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13762026/10/28 14:34:51 WARN Failed to register uploaded object key=6xvplsl61cb5pp50kcawsn2nzlifv3g8.ls error="server returned 404: 404 page not found\n"13772026/10/28 14:34:51 INFO Completed push id=3 objects=3 duration=19.546959ms13782026/10/28 14:34:51 INFO Upload complete. (1.57s)1379=== NAME TestClientIntegration1380 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1381 client_integration_test.go:392: Decompressed .ls content (49 bytes):1382 {"version":1,"root":{"type":"regular","size":39}}13832026/10/28 14:34:51 INFO Received uploads request method=POST path=/api/pending_closures13842026/10/28 14:34:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1385--- PASS: TestClientPushesUseOnePush (20.71s)1386=== CONT TestService_ReadAuthMiddleware13872026/10/28 14:34:51 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>13882026/10/28 14:34:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmIxNjAyYjE4LTY2OGUtNDczNi1hOTk0LWQzZDRjNGJhMjkxM3gxNzkzMTk4MDg0MjUxMjA5MDAw parts=1013892026/10/28 14:34:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13902026/10/28 14:34:51 INFO Completed upload id=1 objects=2 duration=70.409166ms13912026/10/28 14:34:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001392--- PASS: TestReadProxyNarinfo (21.17s)1393=== CONT TestService_RequireScope_OIDC13942026/10/28 14:34:52 INFO Received uploads request method=POST path=/api/pending_closures13952026/10/28 14:34:52 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmI3YWYzOTUxLWNjYTgtNDI5Zi1hMDJkLTA1NWZmOTgwMDJkZngxNzkzMTk4MDc4MjI0OTg1MDAw parts=1013962026/10/28 14:34:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures13972026/10/28 14:34:52 INFO Aborted multipart uploads count=0 kept=013982026/10/28 14:34:52 INFO Received uploads request method=POST path=/api/pending_closures1399=== NAME TestPinProtectsFromGC1400 client_integration_test.go:854: Pinned store path: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestPinProtectsFromGC681726523/001/store/dspj1ql1sy4xnlxc4dpva0sfxh7rbixf-pinned-file.txt1401 client_integration_test.go:855: Unpinned store path: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestPinProtectsFromGC681726523/001/store/mivdc4l76d2na7zk6875nffyjvp8hz2g-unpinned-file.txt14022026/10/28 14:34:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014032026/10/28 14:34:52 INFO Vacuumed table table=pending_closures14042026/10/28 14:34:52 INFO Vacuumed table table=pending_objects14052026/10/28 14:34:52 INFO Vacuumed table table=multipart_uploads14062026/10/28 14:34:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14072026/10/28 14:34:52 INFO Vacuumed table table=closures14082026/10/28 14:34:52 INFO Vacuumed table table=objects14092026/10/28 14:34:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014102026/10/28 14:34:52 INFO Completed push id=1 objects=4 duration=50.088708ms14112026/10/28 14:34:52 INFO Received push request method=POST path=/api/pushes14122026/10/28 14:34:53 INFO Aborted multipart uploads count=0 kept=01413--- PASS: TestService_createPendingClosureHandler (22.36s)1414=== CONT TestService_AuthMiddleware_OIDC14152026/10/28 14:34:53 WARN Force mode enabled - objects will be deleted immediately without grace period1416--- PASS: TestService_Rustfstest (19.98s)1417=== CONT TestLeadEndsOnShutdown14182026/10/28 14:34:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14192026/10/28 14:34:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50707/oidc14202026/10/28 14:34:54 INFO Received push request method=POST path=/api/pushes14212026/10/28 14:34:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14222026/10/28 14:34:54 INFO Uploading 5rzkzzmgxn33i44bkxm9rl3379bp24yh-lost-commit.txt (152B)14232026/10/28 14:34:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50711/oidc14242026/10/28 14:34:54 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14252026/10/28 14:34:54 INFO Received uploads request method=POST path=/api/pending_closures14262026/10/28 14:34:54 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14272026/10/28 14:34:54 WARN Failed to register uploaded object key=5rzkzzmgxn33i44bkxm9rl3379bp24yh.ls error="server returned 404: 404 page not found\n"14282026/10/28 14:34:54 INFO Received push request method=POST path=/api/pushes14292026/10/28 14:34:54 INFO Signed narinfos id=4 count=114302026/10/28 14:34:54 INFO Uploading 1 narinfos14312026/10/28 14:34:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14322026/10/28 14:34:54 INFO Uploading dspj1ql1sy4xnlxc4dpva0sfxh7rbixf-pinned-file.txt (128B)14332026/10/28 14:34:54 INFO Received complete push request method=POST path=/api/pushes/4/complete14342026/10/28 14:34:54 WARN Failed to register uploaded object key=5rzkzzmgxn33i44bkxm9rl3379bp24yh.narinfo error="server returned 404: 404 page not found\n"14352026/10/28 14:34:54 INFO Completed push id=4 objects=3 duration=48.268416ms14362026/10/28 14:34:54 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:50570/api/pushes/4/complete\": EOF" url=http://127.0.0.1:50570/api/pushes/4/complete14372026/10/28 14:34:54 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=014382026/10/28 14:34:54 INFO Received complete push request method=POST path=/api/pushes/4/complete14392026-10-28 14:34:54.876 UTC [17541] ERROR: Push does not exist: id=414402026-10-28 14:34:54.876 UTC [17541] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14412026-10-28 14:34:54.876 UTC [17541] STATEMENT: -- name: CommitPush :one1442 SELECT commit_push($1::bigint)::bigint1443 14442026/10/28 14:34:54 WARN Push not found id=414452026/10/28 14:34:54 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14462026/10/28 14:34:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14472026/10/28 14:34:54 WARN Failed to register uploaded object key=dspj1ql1sy4xnlxc4dpva0sfxh7rbixf.ls error="server returned 404: 404 page not found\n"14482026/10/28 14:34:54 INFO Vacuumed table table=pending_closures14492026/10/28 14:34:54 INFO Vacuumed table table=pending_objects14502026/10/28 14:34:54 INFO Signed narinfos id=1 count=114512026/10/28 14:34:54 INFO Upload complete. (1.954s)14522026/10/28 14:34:54 INFO Uploading 1 narinfos14532026/10/28 14:34:54 INFO Vacuumed table table=multipart_uploads14542026/10/28 14:34:54 INFO Vacuumed table table=closures1455=== NAME TestClientIntegration1456 client_integration_test.go:422: Retrieved narinfo from S3:1457 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestClientIntegration3217315904/002/store/5rzkzzmgxn33i44bkxm9rl3379bp24yh-lost-commit.txt1458 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1459 Compression: zstd1460 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1461 NarSize: 1521462 References: 1463 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl14642026/10/28 14:34:55 INFO Vacuumed table table=objects1465 client_integration_test.go:425: Testing garbage collection...14662026/10/28 14:34:55 WARN Failed to register uploaded object key=dspj1ql1sy4xnlxc4dpva0sfxh7rbixf.narinfo error="server returned 404: 404 page not found\n"14672026/10/28 14:34:55 INFO Received complete push request method=POST path=/api/pushes/1/complete14682026/10/28 14:34:55 INFO Completed push id=1 objects=3 duration=99.366583ms14692026/10/28 14:34:55 INFO Upload complete. (1.832s)1470--- PASS: TestDeleteClosuresRacingPins (24.63s)14712026/10/28 14:34:55 INFO Received uploads request method=POST path=/api/pending_closures1472=== CONT TestPushDedupSurvivesConcurrentGC14732026/10/28 14:34:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures14742026/10/28 14:34:55 INFO Garbage collection started14752026/10/28 14:34:55 INFO Aborted multipart uploads count=0 kept=014762026/10/28 14:34:56 WARN Force mode enabled - objects will be deleted immediately without grace period14772026/10/28 14:34:56 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14782026/10/28 14:34:56 INFO Received uploads request method=POST path=/api/pending_closures14792026/10/28 14:34:56 INFO Received uploads request method=POST path=/api/pending_closures1480--- PASS: TestPresignedUploadRegisteredBeforeCommit (22.11s)1481=== CONT TestGCMetrics14822026/10/28 14:34:56 INFO Received push request method=POST path=/api/pushes14832026/10/28 14:34:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14842026/10/28 14:34:56 INFO Uploading mivdc4l76d2na7zk6875nffyjvp8hz2g-unpinned-file.txt (128B)14852026/10/28 14:34:56 INFO Received uploads request method=POST path=/api/pending_closures14862026/10/28 14:34:57 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14872026/10/28 14:34:57 WARN Failed to register uploaded object key=mivdc4l76d2na7zk6875nffyjvp8hz2g.ls error="server returned 404: 404 page not found\n"14882026/10/28 14:34:57 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14892026/10/28 14:34:57 INFO Signed narinfos id=2 count=114902026/10/28 14:34:57 INFO Uploading 1 narinfos14912026/10/28 14:34:57 INFO Received complete push request method=POST path=/api/pushes/2/complete14922026/10/28 14:34:57 WARN Failed to register uploaded object key=mivdc4l76d2na7zk6875nffyjvp8hz2g.narinfo error="server returned 404: 404 page not found\n"14932026/10/28 14:34:57 INFO Completed push id=2 objects=3 duration=18.93625ms14942026/10/28 14:34:57 INFO Upload complete. (1.257s)14952026/10/28 14:34:57 INFO Received uploads request method=POST path=/api/pending_closures14962026/10/28 14:34:57 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=0 objects_failed=014972026/10/28 14:34:58 WARN Rate limiter enabled after throttle name=s3-test rate=514982026/10/28 14:34:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1499=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1500 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101501 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0015022026/10/28 14:34:58 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=015032026/10/28 14:34:58 INFO Vacuumed table table=pending_closures15042026/10/28 14:34:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15052026/10/28 14:34:58 INFO Vacuumed table table=pending_objects15062026/10/28 14:34:58 INFO Vacuumed table table=multipart_uploads15072026/10/28 14:34:58 INFO Vacuumed table table=closures15082026/10/28 14:34:58 INFO Vacuumed table table=objects15092026/10/28 14:34:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures15102026/10/28 14:34:58 INFO Garbage collection started1511--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (25.24s)1512=== CONT TestGCBugBareHashReferences15132026/10/28 14:34:58 INFO Aborted multipart uploads count=0 kept=01514=== RUN TestPush_RejectsBadRequests/no_roots1515=== PAUSE TestPush_RejectsBadRequests/no_roots1516=== RUN TestPush_RejectsBadRequests/no_objects1517=== PAUSE TestPush_RejectsBadRequests/no_objects1518=== RUN TestPush_RejectsBadRequests/bad_root1519=== PAUSE TestPush_RejectsBadRequests/bad_root1520=== RUN TestPush_RejectsBadRequests/root_not_in_objects1521=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1522=== CONT TestForceGCDuringPushOffersSweptObject1523=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1524=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1525=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1526=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1527=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15282026/10/28 14:34:58 WARN Force mode enabled - objects will be deleted immediately without grace period15292026/10/28 14:34:58 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjUzM2UwZjU1LWVjNTAtNDA1Yy05OGE2LTEwNGQwMDQ0Y2ZmM3gxNzkzMTk4MDkxMzY4Njc1MDAw parts=1015302026/10/28 14:34:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15312026/10/28 14:34:58 INFO Completed upload id=1 objects=2 duration=27.036791ms15322026/10/28 14:34:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15332026/10/28 14:34:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw15342026/10/28 14:34:59 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw error="Delete \"http://localhost:50455/bucket32/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw\": injected: abort refused"15352026/10/28 14:34:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15362026/10/28 14:34:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw15372026/10/28 14:34:59 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst15382026/10/28 14:34:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15392026/10/28 14:34:59 INFO Received uploads request method=POST path=/api/pending_closures15402026/10/28 14:34:59 INFO Received uploads request method=POST path=/api/pending_closures15412026/10/28 14:34:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw15422026/10/28 14:34:59 INFO Received uploads request method=POST path=/api/pending_closures15432026/10/28 14:34:59 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01544=== NAME TestClientIntegration1545 client_integration_test.go:432: Objects in database after GC:15462026/10/28 14:34:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15472026/10/28 14:34:59 WARN Found objects in DB but missing from S3, will re-upload count=115482026/10/28 14:34:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjNiNjI2MjY1LWQwYTktNGY0YS1hYjNkLTk5MmRjYzIxNGE5MXgxNzkzMTk4MDk3ODI5OTQ2MDAw parts=11549 client_integration_test.go:432: Successfully deleted all objects with GC --force15502026/10/28 14:35:00 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15512026/10/28 14:35:00 INFO Completed upload id=3 objects=2 duration=25.58875ms15522026/10/28 14:35:00 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=015532026/10/28 14:35:00 INFO Vacuumed table table=pending_closures15542026/10/28 14:35:00 INFO Vacuumed table table=pending_objects15552026/10/28 14:35:00 INFO Vacuumed table table=multipart_uploads15562026/10/28 14:35:00 INFO Vacuumed table table=closures15572026/10/28 14:35:00 INFO Vacuumed table table=objects1558--- PASS: TestDeduplicatedObjectsRecordedAsPending (22.60s)1559=== CONT TestPush_SignsNarinfosOfItsPendingObjects1560--- PASS: TestClientIntegration (29.56s)1561=== CONT TestPush_RootsAreLockedInByteOrder1562--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (24.58s)1563=== CONT TestPush_CompleteWaitsForCleanupOfThePush15642026/10/28 14:35:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=015652026/10/28 14:35:00 INFO Received create pin request method=POST path=/api/pins/myapp1566--- PASS: TestService_verifyS3Integrity (29.43s)1567=== CONT TestPush_CompleteCommitsEveryRoot15682026/10/28 14:35:00 INFO Created/updated pin name=myapp store_path=/private/var/tb/7/scratch/a5fcb26c595374a1/build/TestPinProtectsFromGC681726523/001/store/dspj1ql1sy4xnlxc4dpva0sfxh7rbixf-pinned-file.txt narinfo_key=dspj1ql1sy4xnlxc4dpva0sfxh7rbixf.narinfo15692026/10/28 14:35:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures15702026/10/28 14:35:00 INFO Garbage collection started15712026/10/28 14:35:00 INFO Aborted multipart uploads count=0 kept=015722026/10/28 14:35:01 WARN Force mode enabled - objects will be deleted immediately without grace period15732026/10/28 14:35:01 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=015742026/10/28 14:35:01 INFO Vacuumed table table=pending_closures15752026/10/28 14:35:01 INFO Vacuumed table table=pending_objects15762026/10/28 14:35:01 INFO Vacuumed table table=multipart_uploads15772026/10/28 14:35:01 INFO Vacuumed table table=closures15782026/10/28 14:35:01 INFO Vacuumed table table=objects1579--- PASS: TestRegisterCompletedObjectNeedsPendingRow (20.00s)1580=== CONT TestPush_RepeatedRootCommitsOnce15812026/10/28 14:35:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15822026/10/28 14:35:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15832026/10/28 14:35:01 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjk0N2VhMGRkLWIzODUtNGQ4OS1hMDYzLWNhZjI2MWI4Mzg0Y3gxNzkzMTk4MDkyODQxMDQyMDAw parts=1015842026/10/28 14:35:01 INFO Received complete push request method=POST path=/api/pushes/2/complete15852026/10/28 14:35:01 INFO Completed push id=2 objects=4 duration=18.122959ms1586--- PASS: TestGetExistingObjectsLocksRows (19.84s)1587=== CONT TestReadRedirectUsesPublicS3URL15882026/10/28 14:35:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjdiM2IzMjVlLTI2OWQtNDFjNS1hMGU3LWU3MmE3OThlM2I5MHgxNzkzMTk4MDk0NjgxODE0MDAw parts=121589--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (31.31s)1590=== CONT TestReadProxyRangeRequest15912026/10/28 14:35:02 INFO Received uploads request method=POST path=/api/pending_closures1592--- PASS: TestCompletedNarNotReofferedAcrossClosures (28.26s)1593=== CONT TestReadRedirectKeepsNarinfoProxied15942026/10/28 14:35:02 INFO Aborted multipart uploads count=0 kept=015952026/10/28 14:35:02 WARN Force mode enabled - objects will be deleted immediately without grace period15962026/10/28 14:35:02 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=015972026/10/28 14:35:02 INFO Vacuumed table table=pending_closures15982026/10/28 14:35:02 INFO Vacuumed table table=pending_objects15992026/10/28 14:35:02 INFO Vacuumed table table=multipart_uploads16002026/10/28 14:35:02 INFO Vacuumed table table=closures1601=== NAME TestPinProtectsFromGC1602 client_integration_test.go:963: Pin successfully protected closure from garbage collection16032026/10/28 14:35:03 INFO Vacuumed table table=objects16042026/10/28 14:35:03 INFO Aborted multipart uploads count=0 kept=016052026/10/28 14:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period16062026/10/28 14:35:03 INFO Received uploads request method=POST path=/api/pending_closures16072026/10/28 14:35:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1608--- PASS: TestPinProtectsFromGC (32.48s)1609=== CONT TestReadRedirectNar16102026/10/28 14:35:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjJlNDA3MGMxLWUwOWYtNDk3NC1iNDM3LWU2ODliMTUxZjhhNHgxNzkzMTk4MDk2ODE3ODgyMDAw parts=1216112026/10/28 14:35:03 INFO Received uploads request method=POST path=/api/pending_closures16122026/10/28 14:35:03 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=016132026/10/28 14:35:03 INFO Vacuumed table table=pending_closures16142026/10/28 14:35:03 INFO Aborted multipart uploads count=0 kept=016152026/10/28 14:35:03 INFO Vacuumed table table=pending_objects16162026/10/28 14:35:03 INFO Vacuumed table table=multipart_uploads16172026/10/28 14:35:03 INFO Received uploads request method=POST path=/api/pending_closures16182026/10/28 14:35:03 INFO Vacuumed table table=closures16192026/10/28 14:35:03 INFO Vacuumed table table=objects16202026/10/28 14:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period16212026/10/28 14:35:03 INFO Received uploads request method=POST path=/api/pending_closures16222026/10/28 14:35:03 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16232026/10/28 14:35:03 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1624--- PASS: TestSweepSkipsRowsLockedByPush (22.79s)1625=== CONT TestNARDeduplicationMetadataUploadBug1626--- PASS: TestFailedS3DeleteKeepsTombstone (20.63s)1627=== CONT TestDeletePinKeepsRowWhenS3Fails1628--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (16.08s)1629=== CONT TestPresentReportsOnlyClosureRoots16302026/10/28 14:35:05 INFO Aborted multipart uploads count=0 kept=016312026/10/28 14:35:05 WARN Force mode enabled - objects will be deleted immediately without grace period16322026/10/28 14:35:05 INFO Received uploads request method=POST path=/api/pending_closures1633--- PASS: TestTombstonedObjectOfferedWithoutWaiting (16.84s)1634=== CONT TestCreatePinRejectsBadInput1635=== NAME TestRedundantMultipartUpload1636 redundant_multipart_test.go:97: unexpected error: Put "http://localhost:50455/bucket31/nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=rustfsadmin%2F20261028%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20261028T143503Z&X-Amz-Expires=18000&X-Amz-SignedHeaders=host&partNumber=5&uploadId=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjkzZGVhZjhjLWYxNmQtNGJiMi04MDc4LTBjYWNhOTI0ZDhkMHgxNzkzMTk4MTAzNzkxMjUxMDAw&X-Amz-Signature=3c75b96b1dd95dd3fc57754228737c97d5b8ad0a51ec750e9134b804e21b5e72": context deadline exceeded1637 16382026/10/28 14:35:05 INFO Received uploads request method=POST path=/api/pending_closures16392026/10/28 14:35:06 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=01640--- FAIL: TestRedundantMultipartUpload (30.26s)1641=== CONT TestConcurrentPinUpdatesAgree16422026/10/28 14:35:06 INFO Vacuumed table table=pending_closures16432026/10/28 14:35:06 INFO Vacuumed table table=pending_objects16442026/10/28 14:35:06 INFO Vacuumed table table=multipart_uploads16452026/10/28 14:35:06 INFO Vacuumed table table=closures16462026/10/28 14:35:06 INFO Vacuumed table table=objects16472026/10/28 14:35:06 INFO Aborted multipart uploads count=0 kept=01648--- PASS: TestGCSweepDeliversEachKeyOnce (17.75s)1649=== CONT TestCreatePin_ReservedPins16502026/10/28 14:35:06 WARN Force mode enabled - objects will be deleted immediately without grace period16512026/10/28 14:35:06 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=016522026/10/28 14:35:06 INFO Vacuumed table table=pending_closures16532026/10/28 14:35:06 INFO Vacuumed table table=pending_objects16542026/10/28 14:35:06 INFO Vacuumed table table=multipart_uploads16552026/10/28 14:35:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50825/oidc16562026/10/28 14:35:06 INFO Vacuumed table table=closures16572026/10/28 14:35:06 INFO Vacuumed table table=objects1658--- PASS: TestService_ReadAuthMiddleware (15.09s)1659=== CONT TestOrphanedObjectsGCStressTest1660--- PASS: TestGCSweepSkipsPendingObjects (16.85s)1661=== CONT TestReconnectLeavesObjectsUnlocked16622026/10/28 14:35:06 INFO lead: acquired remote=192.0.2.1:12341663=== RUN TestService_RequireScope_OIDC/builder_may_write1664=== PAUSE TestService_RequireScope_OIDC/builder_may_write1665=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1666=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1667=== RUN TestService_RequireScope_OIDC/ops_may_admin1668=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1669=== RUN TestService_RequireScope_OIDC/ops_may_not_write1670=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1671=== RUN TestService_RequireScope_OIDC/reader_may_not_write1672=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1673=== RUN TestService_RequireScope_OIDC/static_token_may_admin1674=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1675=== RUN TestService_RequireScope_OIDC/static_token_may_write1676=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1677=== RUN TestService_RequireScope_OIDC/reader_may_read1678=== PAUSE TestService_RequireScope_OIDC/reader_may_read1679=== RUN TestService_RequireScope_OIDC/writer_implies_read1680=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1681=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1682=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1683=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1684=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1685=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1686=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1687=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1688=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1689=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1690=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1691=== CONT TestOrphanedObjectsGC1692=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1693=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1694=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1695=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1696=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1697=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1698=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1699=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1700=== CONT TestObjectStatsTrigger17012026/10/28 14:35:07 INFO Received uploads request method=POST path=/api/pending_closures17022026/10/28 14:35:07 INFO Aborted multipart uploads count=0 kept=017032026/10/28 14:35:07 WARN Force mode enabled - objects will be deleted immediately without grace period17042026/10/28 14:35:08 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=017052026/10/28 14:35:08 INFO Vacuumed table table=pending_closures17062026/10/28 14:35:08 INFO Aborted multipart uploads count=0 kept=017072026/10/28 14:35:08 INFO Vacuumed table table=pending_objects17082026/10/28 14:35:08 INFO Vacuumed table table=multipart_uploads17092026/10/28 14:35:08 INFO Vacuumed table table=closures17102026/10/28 14:35:08 INFO lead: released remote=192.0.2.1:123417112026/10/28 14:35:08 INFO Vacuumed table table=objects17122026/10/28 14:35:08 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=01713--- PASS: TestGCMetrics (11.45s)1714=== CONT TestReadProxyDisabled17152026/10/28 14:35:08 INFO Vacuumed table table=pending_closures17162026/10/28 14:35:08 INFO Vacuumed table table=pending_objects17172026/10/28 14:35:08 INFO Vacuumed table table=multipart_uploads1718--- PASS: TestLeadEndsOnShutdown (14.29s)1719=== CONT TestReadProxyConditionalGet17202026/10/28 14:35:08 INFO Vacuumed table table=closures17212026/10/28 14:35:08 INFO Vacuumed table table=objects17222026/10/28 14:35:08 INFO Aborted multipart uploads count=0 kept=017232026/10/28 14:35:08 WARN Force mode enabled - objects will be deleted immediately without grace period17242026/10/28 14:35:08 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=017252026/10/28 14:35:08 INFO Vacuumed table table=pending_closures17262026/10/28 14:35:08 INFO Vacuumed table table=pending_objects17272026/10/28 14:35:08 INFO Vacuumed table table=multipart_uploads17282026/10/28 14:35:08 INFO Vacuumed table table=closures17292026/10/28 14:35:08 INFO Vacuumed table table=objects1730--- PASS: TestPushDedupSurvivesConcurrentGC (12.68s)1731=== CONT TestReadProxyOutlastsServerWriteTimeout17322026/10/28 14:35:08 INFO Received push request method=POST path=/api/pushes1733--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (9.71s)1734=== CONT TestReadProxyRootRedirectsToIndexHTML1735--- PASS: TestGCBugBareHashReferences (9.88s)1736=== CONT TestReadProxyInvalidPath17372026/10/28 14:35:08 INFO Received push request method=POST path=/api/pushes17382026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17392026/10/28 14:35:08 INFO Signed narinfos id=1 count=117402026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17412026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17422026/10/28 14:35:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"17432026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17442026/10/28 14:35:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"17452026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17462026/10/28 14:35:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=117472026/10/28 14:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17482026/10/28 14:35:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1749--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (8.31s)1750=== CONT TestReadProxy404And42917512026/10/28 14:35:08 INFO Received push request method=POST path=/api/pushes17522026/10/28 14:35:09 INFO Received push request method=POST path=/api/pushes17532026/10/28 14:35:09 INFO Received push request method=POST path=/api/pushes17542026/10/28 14:35:09 INFO Received push request method=POST path=/api/pushes1755--- PASS: TestReadRedirectUsesPublicS3URL (9.33s)1756=== CONT TestReadProxyNarStreaming17572026/10/28 14:35:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1758--- PASS: TestReadProxyRangeRequest (9.87s)1759=== CONT TestReadProxyContentNegotiation17602026/10/28 14:35:12 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjllMDRhM2U0LWViZjgtNDlmNS04NzRiLTM0NmQ4ODMxYjkzMngxNzkzMTk4MTA4ODA5NTI0MDAw parts=1017612026-10-28 14:35:12.507 UTC [27130] ERROR: Push does not exist: id=117622026-10-28 14:35:12.507 UTC [27130] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17632026-10-28 14:35:12.507 UTC [27130] STATEMENT: SELECT commit_push($1)1764--- PASS: TestReadRedirectKeepsNarinfoProxied (10.28s)1765=== CONT TestReadProxyHead1766--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (12.25s)1767=== CONT TestObjectStatsUpdatedOncePerCommit17682026/10/28 14:35:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17692026/10/28 14:35:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1770--- PASS: TestReadRedirectNar (10.15s)1771=== CONT TestCreatePendingClosureRejectsOversizedNAR17722026/10/28 14:35:13 INFO Received uploads request method=POST path=/api/pending_closures1773--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1774=== CONT TestMultipartCleanup17752026/10/28 14:35:13 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjQyZWViN2E5LTZhMzgtNGE3MC1hNjU5LTBkODRmYjc0ZTAzMXgxNzkzMTk4MTA5MDk0ODg3MDAw parts=1017762026/10/28 14:35:14 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjJjNWU3MTY4LWQyODctNDRkYi04MGJiLTAwODFjYTMxY2YxZHgxNzkzMTk4MTA5NDU3OTkyMDAw parts=1017772026/10/28 14:35:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1778=== NAME TestNARDeduplicationMetadataUploadBug1779 metadata_upload_test.go:48: First store path: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestNARDeduplicationMetadataUploadBug1985714874/001/store/5psbad6cvdc7qdd3zfllm0j7dyyb7xw2-file1.txt17802026/10/28 14:35:15 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmNlYjA5YWU5LTU5YzMtNDBiNi1hYjlhLWU3ZTU5MGRiYTRiYngxNzkzMTk4MTEwMTA4NDAxMDAw parts=101781--- PASS: TestPresentReportsOnlyClosureRoots (10.70s)1782=== CONT TestServerTLSConfig1783=== RUN TestServerTLSConfig/no_client_CA1784=== PAUSE TestServerTLSConfig/no_client_CA1785=== RUN TestServerTLSConfig/missing_CA_file1786=== PAUSE TestServerTLSConfig/missing_CA_file1787=== RUN TestServerTLSConfig/not_a_PEM_file1788=== PAUSE TestServerTLSConfig/not_a_PEM_file1789=== CONT TestPendingClosureFailureAbortsItsUploads17902026/10/28 14:35:15 INFO Received create pin request method=POST path=/api/pins/app17912026/10/28 14:35:15 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo17922026/10/28 14:35:15 INFO Received delete pin request method=DELETE path=/api/pins/app17932026/10/28 14:35:15 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket62/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17942026/10/28 14:35:15 INFO Received delete pin request method=DELETE path=/api/pins/app17952026/10/28 14:35:16 INFO Received push request method=POST path=/api/pushes17962026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy17972026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy17982026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy17992026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18002026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18012026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18022026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18032026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18042026/10/28 14:35:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18052026/10/28 14:35:16 INFO Uploading 5psbad6cvdc7qdd3zfllm0j7dyyb7xw2-file1.txt (160B)18062026/10/28 14:35:16 INFO Received create pin request method=POST path=/api/pins/deploy18072026/10/28 14:35:16 INFO Deleted pin name=app18082026/10/28 14:35:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18092026/10/28 14:35:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18102026/10/28 14:35:16 WARN Failed to register uploaded object key=5psbad6cvdc7qdd3zfllm0j7dyyb7xw2.ls error="server returned 404: 404 page not found\n"18112026/10/28 14:35:16 INFO Signed narinfos id=1 count=118122026/10/28 14:35:16 INFO Uploading 1 narinfos18132026/10/28 14:35:16 INFO Received complete push request method=POST path=/api/pushes/1/complete18142026/10/28 14:35:16 WARN Failed to register uploaded object key=5psbad6cvdc7qdd3zfllm0j7dyyb7xw2.narinfo error="server returned 404: 404 page not found\n"1815--- PASS: TestDeletePinKeepsRowWhenS3Fails (12.65s)1816=== CONT TestPendingCleanupUsesOneCutoff18172026/10/28 14:35:17 INFO Completed push id=1 objects=3 duration=47.26ms18182026/10/28 14:35:17 INFO Upload complete. (1.266s)1819=== NAME TestNARDeduplicationMetadataUploadBug1820 metadata_upload_test.go:54: Retrieved narinfo from S3:1821 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestNARDeduplicationMetadataUploadBug1985714874/001/store/5psbad6cvdc7qdd3zfllm0j7dyyb7xw2-file1.txt1822 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1823 Compression: zstd1824 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1825 NarSize: 1601826 References: 1827 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1828 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1829 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1830 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18312026/10/28 14:35:17 INFO Received create pin request method=POST path=/api/pins/app1832 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestNARDeduplicationMetadataUploadBug1985714874/001/store/biq3mx2k2jhi9lnhyb7mj1szqm91ir38-file2.txt18332026/10/28 14:35:17 INFO Received create pin request method=POST path=/api/pins/app18342026/10/28 14:35:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18352026/10/28 14:35:18 WARN Refused reserved pin name=worker-x86_64-linux18362026/10/28 14:35:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18372026/10/28 14:35:18 INFO Received create pin request method=POST path=/api/pins/my-app18382026/10/28 14:35:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18392026/10/28 14:35:18 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1840--- PASS: TestCreatePin_ReservedPins (12.16s)1841=== CONT TestPendingClosureFailureTracksEveryUpload1842=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1843=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1844=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1845=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1846=== CONT TestCacheConfigHandlerMaxNarSize1847--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1848=== CONT TestService_NativeMTLS18492026/10/28 14:35:18 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo18502026/10/28 14:35:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1851--- PASS: TestConcurrentPinUpdatesAgree (12.82s)1852=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded18532026/10/28 14:35:19 INFO Received push request method=POST path=/api/pushes18542026/10/28 14:35:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18552026/10/28 14:35:19 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmNhN2I0YTg1LWQwYWEtNDA0ZC05MzA0LTNmMzczMzg0NjYyMngxNzkzMTk4MTA5MDk0NDA1MDAw parts=1018562026/10/28 14:35:19 WARN Failed to register uploaded object key=biq3mx2k2jhi9lnhyb7mj1szqm91ir38.ls error="server returned 404: 404 page not found\n"18572026/10/28 14:35:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18582026/10/28 14:35:19 INFO Signed narinfos id=2 count=118592026/10/28 14:35:19 INFO Uploading 1 narinfos18602026/10/28 14:35:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18612026/10/28 14:35:19 WARN Failed to register uploaded object key=biq3mx2k2jhi9lnhyb7mj1szqm91ir38.narinfo error="server returned 404: 404 page not found\n"18622026/10/28 14:35:19 INFO Received complete push request method=POST path=/api/pushes/2/complete18632026/10/28 14:35:19 INFO Completed push id=2 objects=3 duration=14.761083ms18642026/10/28 14:35:19 INFO Upload complete. (1.18s)1865=== NAME TestNARDeduplicationMetadataUploadBug1866 metadata_upload_test.go:76: Retrieved narinfo from S3:1867 StorePath: /private/var/tb/7/scratch/a5fcb26c595374a1/build/TestNARDeduplicationMetadataUploadBug1985714874/001/store/biq3mx2k2jhi9lnhyb7mj1szqm91ir38-file2.txt1868 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1869 Compression: zstd1870 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1871 NarSize: 1601872 References: 1873 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1874 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1875 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1876 {"version":1,"root":{"type":"regular","size":44}}1877--- PASS: TestReconnectLeavesObjectsUnlocked (13.16s)1878=== CONT TestGenerateLandingPage1879--- PASS: TestGenerateLandingPage (0.00s)1880=== CONT TestMetricsCommit18812026/10/28 14:35:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjk2NzI5MjYyLTdlOWQtNDliOS05NTkwLWIyNjFhZDc5NGEyZXgxNzkzMTk4MTA5NDU4MTU1MDAw parts=101882--- PASS: TestNARDeduplicationMetadataUploadBug (15.87s)1883=== CONT TestChildrenInheritRaisedFileLimit18842026/10/28 14:35:20 INFO Received create pin request method=POST path=/api/pins/deploy1885--- PASS: TestChildrenInheritRaisedFileLimit (0.12s)1886=== CONT TestMetricsInventory18872026/10/28 14:35:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18882026/10/28 14:35:20 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo18892026/10/28 14:35:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjA3ZDViZGFjLTE5OGEtNDdkMy1iYjIyLTA5MjU1YTI0ZWQyNngxNzkzMTk4MTEwMTMzODUzMDAw parts=1018902026/10/28 14:35:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18912026/10/28 14:35:20 INFO Completed push id=1 objects=4 duration=44.466959ms1892--- PASS: TestCreatePinRejectsBadInput (15.13s)1893=== CONT TestService_readinessHandler1894--- PASS: TestPush_RepeatedRootCommitsOnce (19.63s)1895=== CONT TestGCAdvisoryLockBlocksConcurrentRun1896--- PASS: TestObjectStatsTrigger (14.46s)1897=== CONT TestLeadIncumbentAnnouncesAtOnce1898--- PASS: TestReadProxyConditionalGet (14.94s)1899=== CONT TestGracefulShutdownDrainsInflight19002026/10/28 14:35:23 INFO Starting HTTP server address=127.0.0.1:5100119012026/10/28 14:35:23 INFO Shutdown signal received, draining in-flight requests timeout=10s1902--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1903=== CONT TestLeadElectsOneAndHandsOver19042026/10/28 14:35:23 WARN readiness check failed error="closed pool"1905--- PASS: TestService_readinessHandler (2.84s)1906=== CONT TestClientErrorHandling1907=== RUN TestClientErrorHandling/InvalidStorePath1908=== PAUSE TestClientErrorHandling/InvalidStorePath1909=== RUN TestClientErrorHandling/InvalidAuthToken1910=== PAUSE TestClientErrorHandling/InvalidAuthToken1911=== RUN TestClientErrorHandling/ServerNotAvailable1912=== PAUSE TestClientErrorHandling/ServerNotAvailable1913=== CONT TestGCTaskStore_Fail1914--- PASS: TestGCTaskStore_Fail (0.00s)1915=== CONT TestCacheStatsHandler19162026/10/28 14:35:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19172026/10/28 14:35:24 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjllMzNlY2QzLTRhNmUtNGIxZC05ZWJlLTg0MGU5NmY0ZDA0OHgxNzkzMTk4MTA5MDk0OTQyMDAw parts=101918--- PASS: TestReadProxyDisabled (16.20s)1919=== CONT TestGCTaskStore_GetEmpty1920--- PASS: TestGCTaskStore_GetEmpty (0.00s)1921=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19222026/10/28 14:35:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19232026/10/28 14:35:25 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjZiNjVjNTkxLTYwOGMtNGE1Ny1iOTZjLTk5YWE2ODlhNDczYngxNzkzMTk4MTA5NDU4MTI1MDAw parts=1019242026/10/28 14:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete19252026/10/28 14:35:25 INFO Completed push id=1 objects=6 duration=66.119125ms1926=== NAME TestOrphanedObjectsGC1927 orphaned_objects_gc_test.go:287: GC Test Summary:1928 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1929 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1930 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1931 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1932 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1933--- PASS: TestPush_CompleteCommitsEveryRoot (25.33s)1934=== CONT TestGCTaskStore_DeduplicateSameParams1935--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1936=== CONT TestService_healthCheckHandler1937--- PASS: TestReadProxyRootRedirectsToIndexHTML (17.74s)1938=== CONT TestGCTaskStore_PhaseUpdates1939--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1940=== CONT TestConnectWaitsForAPeerMigration1941--- PASS: TestOrphanedObjectsGC (18.88s)1942=== CONT TestGCTaskStore_StartNew1943--- PASS: TestGCTaskStore_StartNew (0.00s)1944=== CONT TestGCTaskStore_CompletedAllowsNewTask1945--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1946=== CONT TestCommitRacingPendingCleanupKeepsObjects1947--- PASS: TestReadProxyInvalidPath (18.26s)1948=== CONT TestService_AuthMiddleware_MTLSProxyHeader1949--- PASS: TestConnectWaitsForAPeerMigration (1.69s)1950=== CONT TestGCTaskStore_GetReturnsLatest1951--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1952=== CONT TestGCTaskStore_ConflictDifferentParams1953--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1954=== CONT TestCacheConfigHandler1955=== RUN TestCacheConfigHandler/full_config,_no_issuer1956=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1957=== RUN TestCacheConfigHandler/no_cache_url_configured1958=== PAUSE TestCacheConfigHandler/no_cache_url_configured1959=== RUN TestCacheConfigHandler/no_signing_keys1960=== PAUSE TestCacheConfigHandler/no_signing_keys1961=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1962=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1963=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1964--- PASS: TestReadProxyNarStreaming (16.81s)1965=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19662026/10/28 14:35:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19672026/10/28 14:35:28 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmNhN2JjMmEyLTlhODctNDc2OS1iODY5LWVkN2U5ZjM0ZDUzNHgxNzkzMTk4MTA5MTAwNTg3MDAw parts=1019682026/10/28 14:35:29 WARN Rate limiter enabled after throttle name=s3-test rate=519692026/10/28 14:35:29 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."19702026/10/28 14:35:29 WARN Rate limiter backed off name=s3-test rate=519712026/10/28 14:35:29 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1972--- PASS: TestReadProxy404And429 (20.77s)1973=== CONT TestResolveDBConnectionString/flag_wins1974=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1975=== CONT TestResolveDBConnectionString/nothing_configured1976=== CONT TestResolveDBConnectionString/missing_file_is_an_error1977=== CONT TestResolveDBConnectionString/file_when_flag_empty1978=== CONT TestIsValidCachePath/narinfo1979--- PASS: TestResolveDBConnectionString (0.00s)1980 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1981 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1982 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1983 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1984 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1985=== CONT TestIsValidCachePath/traversal_parent1986=== CONT TestIsValidCachePath/short_hash1987=== CONT TestIsValidCachePath/leading_slash1988=== CONT TestIsValidCachePath/wrong_extension1989=== CONT TestIsValidCachePath/empty1990=== CONT TestIsValidCachePath/invalid_char_u1991=== CONT TestIsValidCachePath/random_path1992=== CONT TestIsValidCachePath/invalid_char_e1993=== CONT TestIsValidCachePath/traversal_in_middle1994=== CONT TestIsValidCachePath/index.html1995=== CONT TestIsValidCachePath/nar_bz21996=== CONT TestIsValidCachePath/realisation1997=== CONT TestIsValidCachePath/log1998=== CONT TestIsValidCachePath/nix-cache-info1999=== CONT TestIsValidCachePath/nar_uncompressed2000=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2001=== CONT TestIsValidCachePath/ls2002=== CONT TestIsValidCachePath/nar_xz2003=== CONT TestIsValidCachePath/nar_zst2004--- PASS: TestIsValidCachePath (0.02s)2005 --- PASS: TestIsValidCachePath/narinfo (0.00s)2006 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2007 --- PASS: TestIsValidCachePath/short_hash (0.00s)2008 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2009 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2010 --- PASS: TestIsValidCachePath/empty (0.00s)2011 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2012 --- PASS: TestIsValidCachePath/random_path (0.00s)2013 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2014 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2015 --- PASS: TestIsValidCachePath/index.html (0.00s)2016 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2017 --- PASS: TestIsValidCachePath/realisation (0.00s)2018 --- PASS: TestIsValidCachePath/log (0.00s)2019 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2020 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2021 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2022 --- PASS: TestIsValidCachePath/ls (0.00s)2023 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2024 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2025=== CONT TestParseSingleRange/malformed_both_empty2026=== CONT TestParseSingleRange/start_far_past_EOF2027=== CONT TestParseSingleRange/start_past_EOF2028=== CONT TestParseSingleRange/single_byte2029=== CONT TestParseSingleRange/end_clamped_to_size2030=== CONT TestParseSingleRange/open-ended2031=== CONT TestParseSingleRange/closed2032=== CONT TestParseSingleRange/suffix2033=== CONT TestParseSingleRange/malformed_end_before_start2034=== CONT TestParseSingleRange/malformed_no_dash2035=== CONT TestParseSingleRange/multi-range_ignored2036=== CONT TestParseSingleRange/unknown_unit2037=== CONT TestParseSingleRange/none2038=== CONT TestParseSingleRange/suffix_exceeds_size2039--- PASS: TestParseSingleRange (0.02s)2040 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2041 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2042 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2043 --- PASS: TestParseSingleRange/single_byte (0.00s)2044 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2045 --- PASS: TestParseSingleRange/open-ended (0.00s)2046 --- PASS: TestParseSingleRange/closed (0.00s)2047 --- PASS: TestParseSingleRange/suffix (0.00s)2048 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2049 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2050 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2051 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2052 --- PASS: TestParseSingleRange/none (0.00s)2053 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2054=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20552026/10/28 14:35:29 INFO Received complete multipart upload request method=POST path=/2056--- PASS: TestReadProxyOutlastsServerWriteTimeout (21.56s)2057=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20582026/10/28 14:35:29 INFO Received uploads request method=POST path=/2059--- PASS: TestObjectStatsUpdatedOncePerCommit (17.09s)2060=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20612026/10/28 14:35:29 INFO Received request for more parts method=POST path=/2062--- PASS: TestReadProxyContentNegotiation (17.98s)2063=== CONT TestIsValidUploadKey/nar_plain2064=== CONT TestIsValidUploadKey/empty_key2065=== CONT TestIsValidUploadKey/unknown_type2066=== CONT TestIsValidUploadKey/traversal_nar2067=== CONT TestIsValidUploadKey/absolute2068=== CONT TestIsValidUploadKey/traversal2069=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2070=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2071=== CONT TestIsValidUploadKey/index.html2072=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2073=== CONT TestIsValidUploadKey/nix-cache-info2074=== CONT TestIsValidUploadKey/realisation_plus_in_output2075=== CONT TestIsValidUploadKey/realisation2076=== CONT TestIsValidUploadKey/build_log_equals2077=== CONT TestIsValidUploadKey/build_log_question_mark2078=== CONT TestIsValidUploadKey/build_log_plus_in_name2079=== CONT TestIsValidUploadKey/build_log2080=== CONT TestIsValidUploadKey/build_log_home-manager_file2081=== CONT TestIsValidUploadKey/listing2082=== CONT TestIsValidUploadKey/nar_xz2083=== CONT TestIsValidUploadKey/nar_zst2084=== CONT TestIsValidUploadKey/narinfo2085=== CONT TestPendingClosureWriteTimeout/670k_objects2086--- PASS: TestIsValidUploadKey (0.00s)2087 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2088 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2089 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2090 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2091 --- PASS: TestIsValidUploadKey/absolute (0.00s)2092 --- PASS: TestIsValidUploadKey/traversal (0.00s)2093 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2094 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2095 --- PASS: TestIsValidUploadKey/index.html (0.00s)2096 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2097 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2098 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2099 --- PASS: TestIsValidUploadKey/realisation (0.01s)2100 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2101 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2102 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2103 --- PASS: TestIsValidUploadKey/build_log (0.00s)2104 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2105 --- PASS: TestIsValidUploadKey/listing (0.00s)2106 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2107 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2108 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2109=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2110--- PASS: TestReadProxyHead (17.63s)2111=== CONT TestPendingClosureWriteTimeout/400_objects2112=== CONT TestPendingClosureWriteTimeout/empty2113=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21142026/10/28 14:35:30 INFO Received uploads request method=POST path=/2115=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21162026/10/28 14:35:30 INFO Received request for more parts method=POST path=/2117=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21182026/10/28 14:35:30 INFO Received complete multipart upload request method=POST path=/2119=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21202026/10/28 14:35:30 INFO Received uploads request method=POST path=/2121=== CONT TestProxyWriteTimeout/narinfo2122--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2123 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2124 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.01s)2125 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2126 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2127=== CONT TestProxyWriteTimeout/10_GiB_nar2128=== CONT TestProxyWriteTimeout/unknown_size2129=== CONT TestProxyWriteTimeout/1_GiB_nar2130=== CONT TestGCEndsOnShutdown/before_the_run2131--- PASS: TestProxyWriteTimeout (0.01s)2132 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2133 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2134 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2135 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)21362026/10/28 14:35:30 INFO Received uploads request method=POST path=/api/pending_closures21372026/10/28 14:35:30 INFO Received cleanup request method=DELETE path=/api/pending_closures21382026/10/28 14:35:30 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""21392026/10/28 14:35:30 INFO Aborted multipart uploads count=0 kept=121402026/10/28 14:35:31 INFO Received cleanup request method=DELETE path=/api/pending_closures21412026/10/28 14:35:31 INFO Aborted multipart uploads count=1 kept=021422026/10/28 14:35:31 INFO Received uploads request method=POST path=/api/pending_closures2143--- PASS: TestMultipartCleanup (18.07s)2144=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark21452026/10/28 14:35:32 INFO Received uploads request method=POST path=/api/pending_closures2146--- PASS: TestPendingClosureFailureAbortsItsUploads (17.23s)2147=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete21482026/10/28 14:35:32 INFO Received uploads request method=POST path=/api/pending_closures21492026/10/28 14:35:32 INFO Received cleanup request method=DELETE path=/api/pending_closures2150=== CONT TestPush_RejectsBadRequests/root_not_in_objects21512026/10/28 14:35:33 INFO Received push request method=POST path=/api/pushes2152=== CONT TestPush_RejectsBadRequests/bad_root21532026/10/28 14:35:33 INFO Received push request method=POST path=/api/pushes2154=== CONT TestPush_RejectsBadRequests/no_objects21552026/10/28 14:35:33 INFO Received push request method=POST path=/api/pushes2156=== CONT TestPush_RejectsBadRequests/no_roots21572026/10/28 14:35:33 INFO Received push request method=POST path=/api/pushes2158=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2159=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows21602026/10/28 14:35:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21612026/10/28 14:35:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"21622026/10/28 14:35:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2163--- PASS: TestService_NativeMTLS (15.11s)2164=== CONT TestService_RequireScope_OIDC/ops_may_admin2165=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2166=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21672026/10/28 14:35:33 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]2168=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2169=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2170=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2171=== CONT TestService_RequireScope_OIDC/writer_implies_read2172=== CONT TestService_RequireScope_OIDC/reader_may_read2173=== CONT TestService_RequireScope_OIDC/static_token_may_write2174=== CONT TestService_RequireScope_OIDC/reader_may_not_write2175=== CONT TestService_RequireScope_OIDC/static_token_may_admin2176=== CONT TestService_RequireScope_OIDC/ops_may_not_write2177=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2178=== CONT TestService_RequireScope_OIDC/builder_may_write2179=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2180=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2181=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21822026/10/28 14:35:33 WARN Authentication failed token_preview=eyJhbGciOi...3tfLGRU6mw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2183=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21842026/10/28 14:35:33 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]2185=== CONT TestServerTLSConfig/missing_CA_file2186=== CONT TestServerTLSConfig/not_a_PEM_file2187=== CONT TestServerTLSConfig/no_client_CA2188--- PASS: TestServerTLSConfig (0.01s)2189 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2190 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2191 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2192=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2193--- PASS: TestPush_RejectsBadRequests (23.04s)2194 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.01s)2195 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2196 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)2197 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)21982026/10/28 14:35:33 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmMzYTRmODU0LTA5MmMtNDUxNy1hNzM0LWYzOTQ2MWZmMDk1OXgxNzkzMTk4MTA5MDk0ODg3MDAw parts=102199--- PASS: TestService_AuthMiddleware_OIDC (14.90s)2200 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2201 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2202 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.02s)2203 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2204--- PASS: TestService_RequireScope_OIDC (15.99s)2205 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.01s)2206 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.01s)2207 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2208 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2209 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2210 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2211 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2212 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2213 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2214 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2215 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2216 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2217 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2218 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)22192026/10/28 14:35:34 INFO Received uploads request method=POST path=/api/pending_closures2220--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (16.20s)2221=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true22222026/10/28 14:35:35 INFO Received push request method=POST path=/api/pushes22232026-10-28 14:35:35.333 UTC [14878] LOG: checkpoint starting: wal2224--- PASS: TestMetricsInventory (16.47s)2225=== CONT TestClientErrorHandling/InvalidAuthToken22262026/10/28 14:35:37 INFO lead: acquired remote=192.0.2.1:123422272026/10/28 14:35:37 INFO lead: released remote=192.0.2.1:12342228--- PASS: TestLeadIncumbentAnnouncesAtOnce (16.23s)2229=== CONT TestClientErrorHandling/ServerNotAvailable22302026/10/28 14:35:38 INFO lead: acquired remote=192.0.2.1:123422312026/10/28 14:35:38 INFO Aborted multipart uploads count=1 kept=022322026/10/28 14:35:39 INFO Received cleanup request method=DELETE path=/api/pending_closures22332026/10/28 14:35:39 INFO Aborted multipart uploads count=1 kept=022342026/10/28 14:35:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22352026/10/28 14:35:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22362026/10/28 14:35:39 WARN Request failed, retrying attempt=2 backoff=212.124191ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2237--- PASS: TestPendingCleanupUsesOneCutoff (22.69s)2238=== CONT TestClientErrorHandling/InvalidStorePath22392026/10/28 14:35:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLjE4OTViYjhhLTVmYjUtNGRjZi04YzdkLTc2NjE0ZjU3MGU4MHgxNzkzMTk4MTA5MTAwNTg3MDAw parts=1022402026/10/28 14:35:39 WARN Request failed, retrying attempt=3 backoff=365.098762ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22412026/10/28 14:35:40 INFO lead: released remote=192.0.2.1:123422422026/10/28 14:35:40 INFO lead: acquired remote=192.0.2.1:123422432026-10-28 14:35:40.209 UTC [26566] ERROR: could not obtain lock on row in relation "closures"22442026-10-28 14:35:40.209 UTC [26566] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2245--- PASS: TestCacheStatsHandler (16.79s)2246=== CONT TestCacheConfigHandler/full_config,_no_issuer2247=== CONT TestCacheConfigHandler/no_signing_keys22482026-10-28 14:35:40.270 UTC [26566] ERROR: could not obtain lock on row in relation "closures"22492026-10-28 14:35:40.270 UTC [26566] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2250=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2251=== CONT TestCacheConfigHandler/no_cache_url_configured2252--- PASS: TestCacheConfigHandler (0.00s)2253 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2254 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2255 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2256 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)22572026/10/28 14:35:40 WARN Request failed, retrying attempt=4 backoff=866.591696ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22582026-10-28 14:35:40.332 UTC [26566] ERROR: could not obtain lock on row in relation "closures"22592026-10-28 14:35:40.332 UTC [26566] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22602026-10-28 14:35:40.371 UTC [26566] ERROR: could not obtain lock on row in relation "closures"22612026-10-28 14:35:40.371 UTC [26566] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22622026-10-28 14:35:40.459 UTC [26566] ERROR: could not obtain lock on row in relation "closures"22632026-10-28 14:35:40.459 UTC [26566] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22642026/10/28 14:35:40 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22652026/10/28 14:35:40 WARN mTLS auth: bound subjects configured but subject DN unavailable22662026/10/28 14:35:40 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2267--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (16.77s)2268--- PASS: TestPush_RootsAreLockedInByteOrder (40.62s)22692026/10/28 14:35:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22702026/10/28 14:35:41 WARN Request failed, retrying attempt=5 backoff=1.53496916s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22712026/10/28 14:35:41 ERROR lead error="context canceled"22722026/10/28 14:35:41 INFO lead: released remote=192.0.2.1:12342273--- PASS: TestLeadElectsOneAndHandsOver (18.54s)22742026/10/28 14:35:41 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmE5NTE2ZTRmLTI5OWMtNDhlMi05YjYzLTE2YjMzMzM1NmQ1YngxNzkzMTk4MTM1MjYxOTQwMDAw parts=102275--- PASS: TestService_healthCheckHandler (15.89s)22762026/10/28 14:35:43 INFO Aborted multipart uploads count=0 kept=022772026/10/28 14:35:43 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22782026/10/28 14:35:43 WARN Force mode enabled - objects will be deleted immediately without grace period22792026/10/28 14:35:43 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=022802026/10/28 14:35:43 WARN Request failed, retrying attempt=2 backoff=183.63107ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22812026/10/28 14:35:43 INFO Vacuumed table table=pending_closures22822026/10/28 14:35:43 INFO Vacuumed table table=pending_objects22832026/10/28 14:35:43 INFO Vacuumed table table=multipart_uploads22842026/10/28 14:35:43 INFO Vacuumed table table=closures22852026/10/28 14:35:43 INFO Vacuumed table table=objects22862026/10/28 14:35:43 WARN Request failed, retrying attempt=3 backoff=422.734423ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2287--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (16.85s)2288--- PASS: TestCommitRacingPendingCleanupKeepsObjects (17.44s)22892026/10/28 14:35:44 WARN Request failed, retrying attempt=4 backoff=778.64763ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22902026/10/28 14:35:44 WARN Request failed, retrying attempt=5 backoff=1.566432935s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22912026/10/28 14:35:45 INFO Received uploads request method=POST path=/api/pending_closures2292--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2293 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (17.15s)2294 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (17.62s)22952026/10/28 14:35:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22962026/10/28 14:35:46 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmMxZjUzYTJlLTE0ODktNGJjZi1iMmI5LWQ3MzhhYzVkNGI4MHgxNzkzMTk4MTM1Mjc1MTAwMDAw parts=1022972026/10/28 14:35:46 INFO Received complete push request method=POST path=/api/pushes/1/complete22982026/10/28 14:35:46 INFO Completed push id=1 objects=4 duration=34.505666ms22992026/10/28 14:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23002026/10/28 14:35:46 INFO Completed upload id=2 objects=2 duration=35.3335ms23012026/10/28 14:35:46 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"23022026/10/28 14:35:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23032026/10/28 14:35:46 WARN Request failed, retrying attempt=2 backoff=203.109537ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2304--- PASS: TestMetricsCommit (26.83s)2305--- PASS: TestPendingClosureWriteTimeout (0.00s)2306 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2307 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2308 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2309 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (16.74s)23102026/10/28 14:35:46 WARN Request failed, retrying attempt=3 backoff=427.201425ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23112026/10/28 14:35:47 WARN Request failed, retrying attempt=4 backoff=803.745343ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23122026/10/28 14:35:47 INFO Aborted multipart uploads count=0 kept=023132026/10/28 14:35:47 WARN Force mode enabled - objects will be deleted immediately without grace period23142026/10/28 14:35:48 INFO Aborted multipart uploads count=0 kept=023152026/10/28 14:35:48 WARN Force mode enabled - objects will be deleted immediately without grace period23162026/10/28 14:35:48 WARN Request failed, retrying attempt=5 backoff=1.598836959s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23172026/10/28 14:35:48 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:50455/bucket101/?delete=\": context canceled"2318--- PASS: TestGCEndsOnShutdown (0.00s)2319 --- PASS: TestGCEndsOnShutdown/before_the_run (16.39s)2320 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (16.24s)2321 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (16.20s)23222026/10/28 14:35:48 INFO Received uploads request method=POST path=/api/pending_closures23232026/10/28 14:35:48 INFO Aborted multipart uploads count=0 kept=023242026/10/28 14:35:49 WARN Force mode enabled - objects will be deleted immediately without grace period23252026/10/28 14:35:49 INFO Received uploads request method=POST path=/api/pending_closures23262026/10/28 14:35:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23272026/10/28 14:35:49 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=023282026/10/28 14:35:49 WARN Request failed, retrying attempt=2 backoff=216.472483ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23292026/10/28 14:35:49 INFO Vacuumed table table=pending_closures23302026/10/28 14:35:50 INFO Vacuumed table table=pending_objects23312026/10/28 14:35:50 INFO Vacuumed table table=multipart_uploads23322026/10/28 14:35:50 INFO Vacuumed table table=closures23332026/10/28 14:35:50 INFO Vacuumed table table=objects23342026/10/28 14:35:50 INFO Aborted multipart uploads count=0 kept=023352026/10/28 14:35:50 WARN Force mode enabled - objects will be deleted immediately without grace period23362026/10/28 14:35:50 WARN Request failed, retrying attempt=3 backoff=373.312838ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23372026/10/28 14:35:50 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023382026/10/28 14:35:50 INFO Vacuumed table table=pending_closures23392026/10/28 14:35:50 INFO Vacuumed table table=pending_objects23402026/10/28 14:35:50 INFO Vacuumed table table=multipart_uploads23412026/10/28 14:35:50 INFO Vacuumed table table=closures23422026/10/28 14:35:50 INFO Vacuumed table table=objects23432026/10/28 14:35:50 INFO Received uploads request method=POST path=/api/pending_closures23442026/10/28 14:35:50 WARN Request failed, retrying attempt=4 backoff=846.224083ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2345--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2346 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (17.94s)2347 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (17.86s)23482026/10/28 14:35:51 INFO Received uploads request method=POST path=/api/pending_closures23492026/10/28 14:35:51 WARN Request failed, retrying attempt=5 backoff=1.491579544s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23502026/10/28 14:35:51 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=Y2FmZDkyYjctMTc5ZC00YjNjLTljZGUtNjc4M2JlNDg4ZDVjLmY3OTdlMmUxLWQ5MWQtNDJiZC05NTc0LTI1ODM3MTQ2ODE3M3gxNzkzMTk4MTUxMzQ2OTI5MDAw error="Access Denied"23512026/10/28 14:35:52 WARN keeping failed pending closure for cleanup to retry the abort id=12352--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2353 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (18.25s)2354 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (17.59s)23552026/10/28 14:35:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23562026/10/28 14:35:53 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld7 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"23572026/10/28 14:35:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2358--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (33.08s)2359--- PASS: TestClientErrorHandling (0.00s)2360 --- PASS: TestClientErrorHandling/ServerNotAvailable (14.80s)2361 --- PASS: TestClientErrorHandling/InvalidAuthToken (17.40s)2362 --- PASS: TestClientErrorHandling/InvalidStorePath (15.08s)2363--- PASS: TestUploadHandlersRejectOversizedBody (0.42s)2364 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (3.17s)2365 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (3.69s)2366 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (27.58s)2367=== NAME TestOrphanedObjectsGCStressTest2368 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2369 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2370 orphaned_objects_gc_test.go:503: Stress test completed successfully:2371 orphaned_objects_gc_test.go:504: - Active objects preserved: 202372 orphaned_objects_gc_test.go:505: - Objects deleted: 2102373 orphaned_objects_gc_test.go:506: - Total GC'd: 2102374--- PASS: TestOrphanedObjectsGCStressTest (60.77s)2375FAIL23762026-10-28 14:36:07.660 UTC [14873] LOG: received smart shutdown request23772026-10-28 14:36:07.662 UTC [14873] LOG: background worker "logical replication launcher" (PID 14883) exited with exit code 123782026-10-28 14:36:10.242 UTC [14878] LOG: checkpoint complete: wrote 6642 buffers (40.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=33.119 s, sync=1.676 s, total=34.909 s; sync files=37087, longest=0.012 s, average=0.001 s; distance=533055 kB, estimate=533055 kB; lsn=0/232103A8, redo lsn=0/2201CD0823792026-10-28 14:36:10.248 UTC [14878] LOG: shutting down23802026-10-28 14:36:10.248 UTC [14878] LOG: checkpoint starting: shutdown immediate23812026-10-28 14:36:10.641 UTC [14878] LOG: checkpoint complete: wrote 3679 buffers (22.5%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.352 s, sync=0.040 s, total=0.394 s; sync files=1084, longest=0.001 s, average=0.001 s; distance=18381 kB, estimate=481588 kB; lsn=0/23210420, redo lsn=0/2321042023822026-10-28 14:36:10.659 UTC [14873] LOG: database system is shut down