niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #422
· 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 TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (1.84s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestSetClientTLSErrors117=== CONT TestPathInfoCACompatibility118=== RUN TestPathInfoCACompatibility/null_ca_field119=== PAUSE TestPathInfoCACompatibility/null_ca_field120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121=== CONT TestSetClientTLS122=== CONT TestStreamPushStopsWhenCanceled123=== CONT TestClientSignaturesByStorePath124--- PASS: TestClientSignaturesByStorePath (0.00s)125=== CONT TestScriptTokenEmptyCommand126=== CONT TestStreamPushReportsSkippedPaths127--- PASS: TestScriptTokenEmptyCommand (0.00s)128=== CONT TestScriptTokenBadJSON129--- PASS: TestStreamPushStopsWhenCanceled (0.00s)130=== CONT TestScriptTokenCachesUntilRefresh131=== CONT TestStreamPushReportsSignatures132=== CONT TestStreamPushRequestLine133=== CONT TestStreamPushGivesUpOnDeadServer134=== CONT TestStreamPushIsolatesFailures135=== CONT TestStreamPushBatchesUnderLoad136=== CONT TestStreamPushReportsEveryPath1372026/10/25 13:22:07 ERROR Upload failed error="connection refused" count=201382026/10/25 13:22:07 ERROR Upload failed error="bad path" count=3139--- PASS: TestStreamPushReportsSkippedPaths (0.00s)140=== CONT TestShellSplitErrors141=== CONT TestShellSplit142=== CONT TestDoWithRetry_FinalResponseBodyReadable143=== CONT TestRetryTimeoutOutlastsMaxRetries144=== CONT TestDoWithRetry_BodyReplayedViaGetBody145=== CONT TestResolveStorePath146=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer147=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess148=== CONT TestRateLimiterFeedback1492026/10/25 13:22:07 ERROR Server seems unavailable, giving up on batch untried=17150=== CONT TestScriptTokenScriptFails151=== RUN TestPathInfoCACompatibility/old_string_format_-_text152=== CONT TestSupersededNARStillUploadsListing1532026/10/25 13:22:07 ERROR Upload failed error=boom count=11542026/10/25 13:22:07 ERROR Upload failed error=boom count=1155=== CONT TestParsePathInfoJSON1562026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=server-test rate=5157--- PASS: TestStreamPushIsolatesFailures (0.00s)158--- PASS: TestShellSplitErrors (0.00s)159--- PASS: TestStreamPushReportsSignatures (0.00s)160--- PASS: TestStreamPushReportsEveryPath (0.00s)161=== CONT TestScriptTokenEmptyToken162--- PASS: TestShellSplit (0.00s)163=== CONT TestPathInfoHashCompatibility164=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon169=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI171=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512172=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== RUN TestSupersededNARStillUploadsListing/small_NAR174=== PAUSE TestSupersededNARStillUploadsListing/small_NAR175=== RUN TestSupersededNARStillUploadsListing/dump_cut_short176=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short177=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails178=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails179=== CONT TestScriptTokenNoExpiryRerunsEveryCall180=== CONT TestParsePathInfoJSONMultiplePaths181=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths182=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text186=== RUN TestParsePathInfoJSON/Nix_format187=== CONT TestGetStorePathHash188=== CONT TestFileTokenMissing189=== RUN TestRateLimiterFeedback/429_enables_limiter190=== CONT TestFileTokenEmpty191=== CONT TestConvertHashToNix32192=== RUN TestSetClientTLSErrors/missing_cert_file193=== PAUSE TestSetClientTLSErrors/missing_cert_file194=== RUN TestSetClientTLSErrors/missing_key_file195--- PASS: TestResolveStorePath (0.01s)196=== CONT TestEncodeNixBase32WithRealHash197--- PASS: TestScriptTokenScriptFails (0.01s)198=== CONT TestEncodeNixBase32199=== RUN TestEncodeNixBase32/test_string_hash200=== PAUSE TestEncodeNixBase32/test_string_hash201=== RUN TestEncodeNixBase32/empty_input202=== PAUSE TestEncodeNixBase32/empty_input203--- PASS: TestEncodeNixBase32WithRealHash (0.00s)204=== CONT TestDumpPathWriterError205=== CONT TestFilterOversizedClosures206=== RUN TestFilterOversizedClosures/no_limit_keeps_everything207=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything208--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)209=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== PAUSE TestSetClientTLSErrors/missing_key_file211=== CONT TestDumpPathSingleFile212=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive213=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== RUN TestPathInfoCACompatibility/new_structured_format_-_text215=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestSetClientTLSErrors/invalid_ca_file219=== PAUSE TestSetClientTLSErrors/invalid_ca_file220=== PAUSE TestParsePathInfoJSON/Nix_format221=== RUN TestParsePathInfoJSON/Lix_format222=== PAUSE TestParsePathInfoJSON/Lix_format223=== RUN TestParsePathInfoJSON/empty_input224=== CONT TestDumpPathMatchesNix225=== PAUSE TestParsePathInfoJSON/empty_input226=== RUN TestParsePathInfoJSON/whitespace_only227=== PAUSE TestParsePathInfoJSON/whitespace_only228=== PAUSE TestRateLimiterFeedback/429_enables_limiter229=== RUN TestRateLimiterFeedback/503_enables_limiter230=== PAUSE TestRateLimiterFeedback/503_enables_limiter231=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter232=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter233=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter234=== RUN TestParsePathInfoJSON/invalid_JSON2352026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:571022362026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=server-test rate=52372026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:571032382026/10/25 13:22:07 WARN Rate limiter backed off name=server-test rate=52392026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:57103240=== RUN TestFilterOversizedClosures/all_closures_skipped241=== PAUSE TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text243=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== CONT TestUploadMultipart_SupersededByPeer245=== RUN TestGetStorePathHash/valid_store_path246=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter247=== RUN TestConvertHashToNix32/SRI_format_to_Nix32248--- PASS: TestFileTokenMissing (0.00s)249=== PAUSE TestParsePathInfoJSON/invalid_JSON250=== CONT TestCaseHackSuffix251=== CONT TestUploadMultipart_FailedPartBufferNotReused252=== RUN TestSetClientTLS/rejects_connection_without_client_cert253=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2542026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:57102255=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2562026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=server-test rate=5257=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA258=== RUN TestSetClientTLS/preserves_debug_logging_transport2592026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:57098260=== PAUSE TestSetClientTLS/preserves_debug_logging_transport261=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun262=== CONT TestFileTokenReadsAndCaches263=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica265=== RUN TestUploadMultipart_SupersededByPeer/exists266=== PAUSE TestGetStorePathHash/valid_store_path267=== CONT TestUploadMultipart_PartsInParallel268=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32269--- PASS: TestFileTokenEmpty (0.00s)270--- PASS: TestDoServerRequestAttachesToken (0.01s)271=== PAUSE TestUploadMultipart_SupersededByPeer/exists272--- PASS: TestScriptTokenBadJSON (0.01s)273=== CONT TestPartSizeForNAR274--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)275=== CONT TestStaticToken276--- PASS: TestFileTokenReadsAndCaches (0.00s)277=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry278=== RUN TestGetStorePathHash/basename_without_hyphen_should_error2792026/10/25 13:22:07 WARN Rate limiter backed off name=server-test rate=5280=== CONT TestRegisterUploadedObjectReusesConnections281=== RUN TestConvertHashToNix32/already_Nix32_format282=== PAUSE TestConvertHashToNix32/already_Nix32_format283=== RUN TestUploadMultipart_SupersededByPeer/missing284=== PAUSE TestUploadMultipart_SupersededByPeer/missing285=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error286=== RUN TestPartSizeForNAR/zero_stays_at_minimum287--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)288=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)289=== CONT TestSupersededNARStillUploadsListing/small_NAR290=== RUN TestConvertHashToNix32/invalid_format291=== PAUSE TestConvertHashToNix32/invalid_format292=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum293--- PASS: TestStaticToken (0.00s)2942026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:571022952026/10/25 13:22:07 INFO Garbage collection started296--- PASS: TestScriptTokenEmptyToken (0.02s)297=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI298=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon299=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails300=== RUN TestPartSizeForNAR/small_stays_at_minimum301=== PAUSE TestPartSizeForNAR/small_stays_at_minimum302=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512303--- PASS: TestPathInfoHashCompatibility (0.00s)304 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)308=== CONT TestSupersededNARStillUploadsListing/dump_cut_short309=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum310=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths311=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum312=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts313=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts314=== RUN TestPartSizeForNAR/1_TiB315=== PAUSE TestPartSizeForNAR/1_TiB316=== RUN TestPartSizeForNAR/5_TiB_S3_max_object317=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object318=== RUN TestPartSizeForNAR/capped_at_5_GiB319=== PAUSE TestPartSizeForNAR/capped_at_5_GiB320=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error321=== CONT TestEncodeNixBase32/empty_input322=== CONT TestSetClientTLSErrors/missing_cert_file323=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error324=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error325=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths326=== CONT TestSetClientTLSErrors/missing_ca_file327--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)329 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)330=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error331=== CONT TestSetClientTLSErrors/missing_key_file332=== CONT TestSetClientTLSErrors/invalid_ca_file333=== CONT TestFilterOversizedClosures/all_closures_skipped334=== CONT TestEncodeNixBase32/test_string_hash335--- PASS: TestEncodeNixBase32 (0.00s)336 --- PASS: TestEncodeNixBase32/empty_input (0.00s)337 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)338=== CONT TestRateLimiterFeedback/429_enables_limiter339=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped340--- PASS: TestSetClientTLSErrors (0.01s)341 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)342 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)343 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3452026/10/25 13:22:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50346=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter347=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3482026/10/25 13:22:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000349--- PASS: TestFilterOversizedClosures (0.00s)350 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)353=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3542026/10/25 13:22:07 INFO Uploading abc-hello (1.0GB)355=== CONT TestRateLimiterFeedback/503_enables_limiter3562026/10/25 13:22:07 INFO Uploading abc-hello (1.0GB)3572026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=s3-test rate=53582026/10/25 13:22:07 INFO Garbage collection started3592026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=server-test rate=53602026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:571233612026/10/25 13:22:07 WARN Rate limiter backed off name=server-test rate=5362=== CONT TestParsePathInfoJSON/Nix_format363=== CONT TestParsePathInfoJSON/whitespace_only364=== CONT TestParsePathInfoJSON/invalid_JSON365=== CONT TestParsePathInfoJSON/Lix_format366=== CONT TestParsePathInfoJSON/empty_input367=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA368--- PASS: TestParsePathInfoJSON (0.01s)369 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)370 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)371 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)372 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)373 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)374=== CONT TestSetClientTLS/rejects_connection_without_client_cert375=== CONT TestSetClientTLS/preserves_debug_logging_transport3762026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:571313772026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=server-test rate=53782026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:571753792026/10/25 13:22:07 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0380--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)381=== CONT TestPathInfoCACompatibility/null_ca_field3822026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:57102383=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method384=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3852026/10/25 13:22:07 WARN Rate limiter backed off name=server-test rate=5386=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive387--- PASS: TestStreamPushRequestLine (0.03s)388=== CONT TestPathInfoCACompatibility/old_string_format_-_text389--- PASS: TestRateLimiterFeedback (0.01s)390 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)392 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)393 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)394=== CONT TestUploadMultipart_SupersededByPeer/exists395=== CONT TestUploadMultipart_SupersededByPeer/missing396--- PASS: TestPathInfoCACompatibility (0.01s)397 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)398 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)399 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)400 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)401 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)402--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)403=== CONT TestConvertHashToNix32/SRI_format_to_Nix32404=== CONT TestConvertHashToNix32/invalid_format405=== CONT TestPartSizeForNAR/5_TiB_S3_max_object406=== CONT TestPartSizeForNAR/zero_stays_at_minimum407=== CONT TestConvertHashToNix32/already_Nix32_format408--- PASS: TestConvertHashToNix32 (0.02s)409 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)410 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)411 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)412=== CONT TestPartSizeForNAR/1_TiB413=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum414=== CONT TestPartSizeForNAR/small_stays_at_minimum415=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts416=== CONT TestPartSizeForNAR/capped_at_5_GiB417--- PASS: TestPartSizeForNAR (0.01s)418 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)419 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)420 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)421 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)422 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)424 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)425=== CONT TestGetStorePathHash/valid_store_path426=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error427=== CONT TestGetStorePathHash/basename_without_hyphen_should_error428=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error429--- PASS: TestGetStorePathHash (0.02s)430 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)431 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)432 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)433 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)4342026/10/25 13:22:07 WARN Garbage collection finished on another replica. Its statistics are not available here4352026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:57102436--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)4372026/10/25 13:22:07 WARN Rate limiter enabled after throttle name=s3-test rate=54382026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:57102439--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)440 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)441 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)4422026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:571024432026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:571024442026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:571024452026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:571024462026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:571024472026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:571024482026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:571024492026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:57102450--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4512026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:571024522026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:571024532026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:571024542026/10/25 13:22:07 http: TLS handshake error from 127.0.0.1:57192: remote error: tls: bad certificate455--- PASS: TestDumpPathSingleFile (0.06s)4562026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:571024572026/10/25 13:22:07 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:57102458--- PASS: TestSetClientTLS (0.02s)459 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)460 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)461 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)462--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)463--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)464--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.07s)465--- PASS: TestDumpPathWriterError (0.07s)466--- PASS: TestCaseHackSuffix (0.07s)4672026/10/25 13:22:07 INFO Uploading abc-hello (1.0GB)4682026/10/25 13:22:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:57143/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:57143/part/24692026/10/25 13:22:07 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"470--- PASS: TestStreamPushBatchesUnderLoad (0.10s)471--- PASS: TestDumpPathMatchesNix (0.11s)472--- PASS: TestSupersededNARStillUploadsListing (0.00s)473 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)474 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)475 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.56s)476--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.57s)477--- PASS: TestUploadMultipart_PartsInParallel (0.62s)4782026/10/25 13:22:08 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57094/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57094/api/uploads/complete4792026/10/25 13:22:08 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4802026/10/25 13:22:08 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57094/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57094/api/uploads/complete4812026/10/25 13:22:08 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"482--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4832026/10/25 13:22:08 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57094/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57094/api/uploads/complete4842026/10/25 13:22:08 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)486PASS487Running server tests...488The files belonging to this database system will be owned by user "_tribuchetbld1".489This user must also own the server process.490491The database cluster will be initialized with locale "C".492The default database encoding has accordingly been set to "SQL_ASCII".493The default text search configuration will be set to "english".494495Data page checksums are enabled.496497creating directory /private/var/tb/1/scratch/78a6254c5a3a7b70/build/postgres1408796993/data ... ok498creating subdirectories ... ok499selecting dynamic shared memory implementation ... posix500selecting default "max_connections" ... 100501selecting default "shared_buffers" ... 128MB502selecting default time zone ... UTC503creating configuration files ... ok504running bootstrap script ... ok505performing post-bootstrap initialization ... ok506syncing data to disk ... ok507508initdb: warning: enabling "trust" authentication for local connections509initdb: 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.510511Success. You can now start the database server using:512513 pg_ctl -D /private/var/tb/1/scratch/78a6254c5a3a7b70/build/postgres1408796993/data -l logfile start5145152026-10-25 13:22:11.066 UTC [29708] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5162026-10-25 13:22:11.066 UTC [29708] LOG: listening on Unix socket "/private/var/tb/1/scratch/78a6254c5a3a7b70/build/postgres1408796993/.s.PGSQL.5432"5172026-10-25 13:22:11.068 UTC [29715] LOG: database system was shut down at 2026-10-25 13:22:11 UTC5182026-10-25 13:22:11.069 UTC [29708] LOG: database system is ready to accept connections519/private/var/tb/1/scratch/78a6254c5a3a7b70/build/postgres1408796993:5432 - accepting connections520{"timestamp":"2026-10-25T13:22:13.270142Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"cf8718b9-dc2a-4aed-8677-44ed9c88990f","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}521{"timestamp":"2026-10-25T13:22:13.374378Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b988b11f-6cc2-4826-bffa-629a94f157f9","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":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}522=== RUN TestService_AuthMiddleware523=== PAUSE TestService_AuthMiddleware524=== RUN TestService_AuthMiddleware_MTLSProxyHeader525=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader526=== RUN TestService_AuthMiddleware_MTLSBoundSubjects527=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects528=== RUN TestService_ReadAuthMiddleware529=== PAUSE TestService_ReadAuthMiddleware530=== RUN TestService_AuthMiddleware_OIDC531=== PAUSE TestService_AuthMiddleware_OIDC532=== RUN TestService_RequireScope_OIDC533=== PAUSE TestService_RequireScope_OIDC534=== RUN TestService_ReadScope_PublicByDefault535=== PAUSE TestService_ReadScope_PublicByDefault536=== RUN TestCacheConfigHandler537=== PAUSE TestCacheConfigHandler538=== RUN TestCacheStatsHandler539=== PAUSE TestCacheStatsHandler540=== RUN TestClientCADerivations541=== PAUSE TestClientCADerivations542=== RUN TestClientErrorHandling543=== PAUSE TestClientErrorHandling544=== RUN TestClientIntegration545=== PAUSE TestClientIntegration546=== RUN TestClientMultipleUploads547=== PAUSE TestClientMultipleUploads548=== RUN TestClientWithDependencies549=== PAUSE TestClientWithDependencies550=== RUN TestClientSharedPathCommittedMidPush551=== PAUSE TestClientSharedPathCommittedMidPush552=== RUN TestPinProtectsFromGC553=== PAUSE TestPinProtectsFromGC554=== RUN TestClientPushesUseOnePush555=== PAUSE TestClientPushesUseOnePush556=== RUN TestClientFallsBackToClosures557=== PAUSE TestClientFallsBackToClosures558=== RUN TestDeleteClosuresRacingPins559=== PAUSE TestDeleteClosuresRacingPins560=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock562=== RUN TestResolveDBConnectionString563=== PAUSE TestResolveDBConnectionString564=== RUN TestConnectWaitsForAPeerMigration565=== PAUSE TestConnectWaitsForAPeerMigration566=== RUN TestLeadElectsOneAndHandsOver567=== PAUSE TestLeadElectsOneAndHandsOver568=== RUN TestLeadIncumbentWinsAfterRestart5692026/10/25 13:22:13 INFO lead: acquired remote=192.0.2.1:12345702026/10/25 13:22:14 INFO lead: released remote=192.0.2.1:12345712026/10/25 13:22:14 INFO lead: acquired remote=192.0.2.1:12345722026/10/25 13:22:15 INFO lead: released remote=192.0.2.1:1234573--- PASS: TestLeadIncumbentWinsAfterRestart (2.16s)574=== RUN TestLeadIncumbentAnnouncesAtOnce575=== PAUSE TestLeadIncumbentAnnouncesAtOnce576=== RUN TestLeadEndsOnShutdown577=== PAUSE TestLeadEndsOnShutdown578=== RUN TestLeadEndsWhenItsConnectionHangs5792026/10/25 13:22:15 INFO lead: acquired remote=192.0.2.1:12345802026-10-25 13:22:17.001 UTC [29751] FATAL: terminating connection due to administrator command5812026/10/25 13:22:17 INFO lead: acquired remote=192.0.2.1:12345822026/10/25 13:22:18 WARN lead: lock connection lost error="timeout: context deadline exceeded"5832026/10/25 13:22:18 INFO lead: released remote=192.0.2.1:12345842026/10/25 13:22:18 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)586=== RUN TestGCAdvisoryLockBlocksConcurrentRun587=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun588=== RUN TestGCBugBareHashReferences589=== PAUSE TestGCBugBareHashReferences590=== RUN TestGCMetrics591=== PAUSE TestGCMetrics592=== RUN TestPushDedupSurvivesConcurrentGC593=== PAUSE TestPushDedupSurvivesConcurrentGC594=== RUN TestDeduplicatedObjectsRecordedAsPending595=== PAUSE TestDeduplicatedObjectsRecordedAsPending596=== RUN TestGCSweepSkipsPendingObjects597=== PAUSE TestGCSweepSkipsPendingObjects598=== RUN TestTombstonedObjectOfferedWithoutWaiting599=== PAUSE TestTombstonedObjectOfferedWithoutWaiting600=== RUN TestGCSweepDeliversEachKeyOnce601=== PAUSE TestGCSweepDeliversEachKeyOnce602=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection604=== RUN TestForceGCDuringPushOffersSweptObject605=== PAUSE TestForceGCDuringPushOffersSweptObject606=== RUN TestFailedS3DeleteKeepsTombstone607=== PAUSE TestFailedS3DeleteKeepsTombstone608=== RUN TestSweepSkipsRowsLockedByPush609=== PAUSE TestSweepSkipsRowsLockedByPush610=== RUN TestRegisterCompletedObjectNeedsPendingRow611=== PAUSE TestRegisterCompletedObjectNeedsPendingRow612=== RUN TestGetExistingObjectsLocksRows613=== PAUSE TestGetExistingObjectsLocksRows614=== RUN TestSweepRechecksPendingAfterLocking615=== PAUSE TestSweepRechecksPendingAfterLocking616=== RUN TestPushWaitsForSweepHoldingRow617=== PAUSE TestPushWaitsForSweepHoldingRow618=== RUN TestCommitRacingPendingCleanupKeepsObjects619=== PAUSE TestCommitRacingPendingCleanupKeepsObjects620=== RUN TestGCEndsOnShutdown621=== PAUSE TestGCEndsOnShutdown622=== RUN TestGCTaskStore_StartNew623=== PAUSE TestGCTaskStore_StartNew624=== RUN TestGCTaskStore_DeduplicateSameParams625=== PAUSE TestGCTaskStore_DeduplicateSameParams626=== RUN TestGCTaskStore_ConflictDifferentParams627=== PAUSE TestGCTaskStore_ConflictDifferentParams628=== RUN TestGCTaskStore_GetEmpty629=== PAUSE TestGCTaskStore_GetEmpty630=== RUN TestGCTaskStore_GetReturnsLatest631=== PAUSE TestGCTaskStore_GetReturnsLatest632=== RUN TestGCTaskStore_CompletedAllowsNewTask633=== PAUSE TestGCTaskStore_CompletedAllowsNewTask634=== RUN TestGCTaskStore_PhaseUpdates635=== PAUSE TestGCTaskStore_PhaseUpdates636=== RUN TestGCTaskStore_Fail637=== PAUSE TestGCTaskStore_Fail638=== RUN TestGracefulShutdownDrainsInflight639=== PAUSE TestGracefulShutdownDrainsInflight640=== RUN TestService_healthCheckHandler641=== PAUSE TestService_healthCheckHandler642=== RUN TestService_readinessHandler643=== PAUSE TestService_readinessHandler644=== RUN TestGenerateLandingPage645=== PAUSE TestGenerateLandingPage646=== RUN TestCacheConfigHandlerMaxNarSize647=== PAUSE TestCacheConfigHandlerMaxNarSize648=== RUN TestCreatePendingClosureRejectsOversizedNAR649=== PAUSE TestCreatePendingClosureRejectsOversizedNAR650=== RUN TestNARDeduplicationMetadataUploadBug651=== PAUSE TestNARDeduplicationMetadataUploadBug652=== RUN TestMetricsInventory653=== PAUSE TestMetricsInventory654=== RUN TestMetricsCommit655=== PAUSE TestMetricsCommit656=== RUN TestService_NativeMTLS657=== PAUSE TestService_NativeMTLS658=== RUN TestServerTLSConfig659=== PAUSE TestServerTLSConfig660=== RUN TestMultipartCleanup661=== PAUSE TestMultipartCleanup662=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded664=== RUN TestPendingCleanupUsesOneCutoff665=== PAUSE TestPendingCleanupUsesOneCutoff666=== RUN TestObjectStatsTrigger667=== PAUSE TestObjectStatsTrigger668=== RUN TestObjectStatsLargeCommit669=== PAUSE TestObjectStatsLargeCommit670=== RUN TestOrphanedObjectsGC671=== PAUSE TestOrphanedObjectsGC672=== RUN TestOrphanedObjectsGCStressTest673=== PAUSE TestOrphanedObjectsGCStressTest674=== RUN TestCreatePin_ReservedPins675=== PAUSE TestCreatePin_ReservedPins676=== RUN TestPresentReportsOnlyClosureRoots677=== PAUSE TestPresentReportsOnlyClosureRoots678=== RUN TestPresentRefreshesOnlyStaleClosures679=== PAUSE TestPresentRefreshesOnlyStaleClosures680=== RUN TestPresentNotReportedWhileGCDeletesClosure681=== PAUSE TestPresentNotReportedWhileGCDeletesClosure682=== RUN TestParseSingleRange683=== PAUSE TestParseSingleRange684=== RUN TestProxyHeadersOnlyTrustedOnSocket6852026/10/25 13:22:18 INFO Starting HTTP server address=127.0.0.1:572716862026/10/25 13:22:18 INFO Starting HTTP server address=proxy.sock6872026/10/25 13:22:18 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6882026/10/25 13:22:18 INFO Shutdown signal received, draining in-flight requests timeout=10s689--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.18s)690=== RUN TestIsValidCachePath691=== PAUSE TestIsValidCachePath692=== RUN TestReadProxyNarinfo693=== PAUSE TestReadProxyNarinfo694=== RUN TestReadProxyNarinfoAlreadyDecompressed695=== PAUSE TestReadProxyNarinfoAlreadyDecompressed696=== RUN TestReadProxyContentNegotiation697=== PAUSE TestReadProxyContentNegotiation698=== RUN TestReadProxyNarStreaming699=== PAUSE TestReadProxyNarStreaming700=== RUN TestReadProxy404701=== PAUSE TestReadProxy404702=== RUN TestReadProxyInvalidPath703=== PAUSE TestReadProxyInvalidPath704=== RUN TestReadProxyHead705=== PAUSE TestReadProxyHead706=== RUN TestReadProxyOutlastsServerWriteTimeout707=== PAUSE TestReadProxyOutlastsServerWriteTimeout708=== RUN TestReadProxyConditionalGet709=== PAUSE TestReadProxyConditionalGet710=== RUN TestReadProxyRootRedirectsToIndexHTML711=== PAUSE TestReadProxyRootRedirectsToIndexHTML712=== RUN TestReadProxyDisabled713=== PAUSE TestReadProxyDisabled714=== RUN TestReadRedirectNar715=== PAUSE TestReadRedirectNar716=== RUN TestReadRedirectKeepsNarinfoProxied717=== PAUSE TestReadRedirectKeepsNarinfoProxied718=== RUN TestReadProxyRangeRequest719=== PAUSE TestReadProxyRangeRequest720=== RUN TestReadRedirectUsesPublicS3URL721=== PAUSE TestReadRedirectUsesPublicS3URL722=== RUN TestPush_OverlappingRootsStoreOneRowPerKey723=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey724=== RUN TestPush_CompleteCommitsEveryRoot725=== PAUSE TestPush_CompleteCommitsEveryRoot726=== RUN TestPush_RepeatedRootCommitsOnce727=== PAUSE TestPush_RepeatedRootCommitsOnce728=== RUN TestPush_CompleteWaitsForCleanupOfThePush729=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush730=== RUN TestPush_RootsAreLockedInByteOrder731=== PAUSE TestPush_RootsAreLockedInByteOrder732=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit733=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit734=== RUN TestPush_RejectsBadRequests735=== PAUSE TestPush_RejectsBadRequests736=== RUN TestPush_SignsNarinfosOfItsPendingObjects737=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects738=== RUN TestRedundantMultipartUpload739=== PAUSE TestRedundantMultipartUpload740=== RUN TestCompleteMultipartUpload_ErrorButObjectExists741=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists742=== RUN TestCompletedNarNotReofferedAcrossClosures743=== PAUSE TestCompletedNarNotReofferedAcrossClosures744=== RUN TestPresignedUploadRegisteredBeforeCommit745=== PAUSE TestPresignedUploadRegisteredBeforeCommit746=== RUN TestService_Rustfstest747=== PAUSE TestService_Rustfstest748=== RUN TestParseSize749=== PAUSE TestParseSize750=== RUN TestSkippedUploadsHandler751=== PAUSE TestSkippedUploadsHandler752=== RUN TestSystemdListenerNotActivated753--- PASS: TestSystemdListenerNotActivated (0.00s)754=== RUN TestWatchdogBeatsWhenHealthy755--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)756=== RUN TestWatchdogSkipsWhenUnhealthy7572026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 13:22:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"767--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)768=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle770=== RUN TestProxyWriteTimeout771=== PAUSE TestProxyWriteTimeout772=== RUN TestPendingClosureWriteTimeout773=== PAUSE TestPendingClosureWriteTimeout774=== RUN TestIsValidUploadKey775=== PAUSE TestIsValidUploadKey776=== RUN TestUploadHandlersRejectInvalidKeys777=== PAUSE TestUploadHandlersRejectInvalidKeys778=== RUN TestUploadHandlersRejectOversizedBody779=== PAUSE TestUploadHandlersRejectOversizedBody780=== RUN TestService_cleanupPendingClosuresHandler781=== PAUSE TestService_cleanupPendingClosuresHandler782=== RUN TestService_createPendingClosureHandler783=== PAUSE TestService_createPendingClosureHandler784=== RUN TestService_verifyS3Integrity785=== PAUSE TestService_verifyS3Integrity786=== RUN TestCompleteMultipartUnregistered787=== PAUSE TestCompleteMultipartUnregistered788=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT789=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT790=== CONT TestService_createPendingClosureHandler791=== CONT TestUploadHandlersRejectOversizedBody792=== CONT TestPendingClosureWriteTimeout793=== CONT TestPush_RejectsBadRequests794=== CONT TestService_AuthMiddleware795=== CONT TestCompleteMultipartUnregistered796=== CONT TestReadProxyHead797=== RUN TestPendingClosureWriteTimeout/empty798=== PAUSE TestPendingClosureWriteTimeout/empty799=== CONT TestService_cleanupPendingClosuresHandler800=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT801=== CONT TestCacheConfigHandlerMaxNarSize802=== CONT TestUploadHandlersRejectInvalidKeys803=== CONT TestIsValidUploadKey804=== CONT TestProxyWriteTimeout805=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle806=== CONT TestSkippedUploadsHandler807=== CONT TestParseSize808=== CONT TestService_Rustfstest809=== CONT TestPresignedUploadRegisteredBeforeCommit810=== CONT TestCompletedNarNotReofferedAcrossClosures811=== CONT TestCompleteMultipartUpload_ErrorButObjectExists812=== CONT TestRedundantMultipartUpload813=== CONT TestPush_SignsNarinfosOfItsPendingObjects814=== CONT TestOrphanedObjectsGCStressTest815=== CONT TestIsValidCachePath816=== RUN TestPendingClosureWriteTimeout/400_objects817=== PAUSE TestPendingClosureWriteTimeout/400_objects818=== RUN TestPendingClosureWriteTimeout/670k_objects819--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)820=== RUN TestProxyWriteTimeout/narinfo821=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822=== RUN TestIsValidUploadKey/narinfo823=== CONT TestParseSingleRange824=== RUN TestParseSingleRange/none825=== PAUSE TestProxyWriteTimeout/narinfo826=== RUN TestProxyWriteTimeout/1_GiB_nar827=== RUN TestIsValidCachePath/narinfo828=== PAUSE TestIsValidCachePath/narinfo829=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars830=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info831=== PAUSE TestPendingClosureWriteTimeout/670k_objects832=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars833=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline834--- PASS: TestParseSize (0.00s)835=== RUN TestIsValidCachePath/nar_zst836=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal837=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal838=== CONT TestPresentNotReportedWhileGCDeletesClosure839=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key8402026/10/25 13:22:18 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000841=== PAUSE TestParseSingleRange/none842=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key843=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key844=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key845=== CONT TestReadProxyNarinfo846=== PAUSE TestIsValidUploadKey/narinfo847=== RUN TestIsValidUploadKey/nar_zst848=== PAUSE TestIsValidUploadKey/nar_zst849=== RUN TestIsValidUploadKey/nar_xz850=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale851=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale852=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh853=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh854=== PAUSE TestProxyWriteTimeout/1_GiB_nar855=== RUN TestProxyWriteTimeout/10_GiB_nar856=== PAUSE TestProxyWriteTimeout/10_GiB_nar857=== RUN TestProxyWriteTimeout/unknown_size858=== PAUSE TestProxyWriteTimeout/unknown_size859=== CONT TestOrphanedObjectsGC860=== CONT TestPresentRefreshesOnlyStaleClosures861=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline862=== CONT TestReadProxyInvalidPath863--- PASS: TestSkippedUploadsHandler (0.04s)864=== CONT TestObjectStatsLargeCommit865=== PAUSE TestIsValidCachePath/nar_zst866=== RUN TestIsValidCachePath/nar_xz867=== PAUSE TestIsValidCachePath/nar_xz868=== RUN TestIsValidCachePath/nar_bz2869=== PAUSE TestIsValidCachePath/nar_bz2870=== RUN TestIsValidCachePath/nar_uncompressed871=== PAUSE TestIsValidCachePath/nar_uncompressed872=== RUN TestIsValidCachePath/ls873=== PAUSE TestIsValidCachePath/ls874=== RUN TestIsValidCachePath/log875=== PAUSE TestIsValidCachePath/log876=== RUN TestIsValidCachePath/realisation877=== PAUSE TestIsValidCachePath/realisation878=== RUN TestParseSingleRange/unknown_unit879=== PAUSE TestParseSingleRange/unknown_unit880=== RUN TestParseSingleRange/multi-range_ignored881=== PAUSE TestParseSingleRange/multi-range_ignored882=== RUN TestParseSingleRange/malformed_no_dash883=== PAUSE TestParseSingleRange/malformed_no_dash884=== RUN TestParseSingleRange/malformed_both_empty885=== PAUSE TestParseSingleRange/malformed_both_empty886=== RUN TestParseSingleRange/malformed_end_before_start887=== PAUSE TestParseSingleRange/malformed_end_before_start888=== RUN TestParseSingleRange/closed889=== PAUSE TestParseSingleRange/closed890=== RUN TestParseSingleRange/open-ended891=== PAUSE TestParseSingleRange/open-ended892=== RUN TestParseSingleRange/end_clamped_to_size893=== PAUSE TestParseSingleRange/end_clamped_to_size894=== RUN TestParseSingleRange/suffix895=== PAUSE TestParseSingleRange/suffix896=== RUN TestParseSingleRange/suffix_exceeds_size897=== PAUSE TestParseSingleRange/suffix_exceeds_size898=== RUN TestParseSingleRange/single_byte899=== PAUSE TestParseSingleRange/single_byte900=== RUN TestParseSingleRange/start_past_EOF901=== PAUSE TestParseSingleRange/start_past_EOF902=== RUN TestParseSingleRange/start_far_past_EOF903=== PAUSE TestParseSingleRange/start_far_past_EOF904=== PAUSE TestIsValidUploadKey/nar_xz905=== RUN TestIsValidUploadKey/nar_plain906=== PAUSE TestIsValidUploadKey/nar_plain907=== RUN TestIsValidUploadKey/listing908=== PAUSE TestIsValidUploadKey/listing909=== RUN TestIsValidUploadKey/build_log910=== PAUSE TestIsValidUploadKey/build_log911=== RUN TestIsValidUploadKey/build_log_home-manager_file912=== PAUSE TestIsValidUploadKey/build_log_home-manager_file913=== RUN TestIsValidUploadKey/build_log_plus_in_name914=== PAUSE TestIsValidUploadKey/build_log_plus_in_name915=== RUN TestIsValidUploadKey/build_log_question_mark916=== PAUSE TestIsValidUploadKey/build_log_question_mark917=== RUN TestIsValidUploadKey/build_log_equals918=== PAUSE TestIsValidUploadKey/build_log_equals919=== RUN TestIsValidUploadKey/realisation920=== PAUSE TestIsValidUploadKey/realisation921=== RUN TestIsValidUploadKey/realisation_plus_in_output922=== PAUSE TestIsValidUploadKey/realisation_plus_in_output923=== RUN TestIsValidUploadKey/nix-cache-info924=== PAUSE TestIsValidUploadKey/nix-cache-info925=== RUN TestIsValidUploadKey/index.html926=== PAUSE TestIsValidUploadKey/index.html927=== RUN TestIsValidUploadKey/narinfo_key,_nar_type928=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type929=== RUN TestIsValidUploadKey/nar_key,_narinfo_type930=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type931=== RUN TestIsValidUploadKey/listing_key,_narinfo_type932=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type933=== RUN TestIsValidUploadKey/traversal934=== PAUSE TestIsValidUploadKey/traversal935=== RUN TestIsValidUploadKey/traversal_nar936=== PAUSE TestIsValidUploadKey/traversal_nar937=== CONT TestPresentReportsOnlyClosureRoots938=== RUN TestIsValidCachePath/nix-cache-info939=== PAUSE TestIsValidCachePath/nix-cache-info940=== RUN TestIsValidCachePath/index.html941=== PAUSE TestIsValidCachePath/index.html942=== RUN TestIsValidCachePath/traversal_parent943=== PAUSE TestIsValidCachePath/traversal_parent944=== RUN TestIsValidCachePath/traversal_in_middle945=== PAUSE TestIsValidCachePath/traversal_in_middle946=== RUN TestIsValidCachePath/invalid_char_e947=== PAUSE TestIsValidCachePath/invalid_char_e948=== RUN TestIsValidCachePath/invalid_char_u949=== PAUSE TestIsValidCachePath/invalid_char_u950=== RUN TestIsValidCachePath/random_path951=== PAUSE TestIsValidCachePath/random_path952=== RUN TestIsValidCachePath/empty953=== PAUSE TestIsValidCachePath/empty954=== RUN TestIsValidCachePath/leading_slash955=== PAUSE TestIsValidCachePath/leading_slash956=== RUN TestIsValidCachePath/wrong_extension957=== PAUSE TestIsValidCachePath/wrong_extension958=== RUN TestIsValidCachePath/short_hash959=== PAUSE TestIsValidCachePath/short_hash960=== CONT TestReadProxy404961=== RUN TestIsValidUploadKey/absolute962=== PAUSE TestIsValidUploadKey/absolute963=== RUN TestIsValidUploadKey/empty_key964=== PAUSE TestIsValidUploadKey/empty_key965=== RUN TestIsValidUploadKey/unknown_type966=== PAUSE TestIsValidUploadKey/unknown_type967=== CONT TestCreatePin_ReservedPins968=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure969=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure970=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart971=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart972=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts973=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts974=== CONT TestReadProxyNarStreaming9752026/10/25 13:22:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57274/oidc9762026/10/25 13:22:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"977--- PASS: TestService_AuthMiddleware (0.61s)978=== CONT TestService_verifyS3Integrity9792026/10/25 13:22:19 INFO Received uploads request method=POST path=/api/pending_closures9802026/10/25 13:22:20 INFO Received uploads request method=POST path=/api/pending_closures9812026/10/25 13:22:20 INFO Received uploads request method=POST path=/api/pending_closures9822026/10/25 13:22:20 INFO Received uploads request method=POST path=/api/pending_closures9832026/10/25 13:22:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9842026/10/25 13:22:20 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst985--- PASS: TestCompleteMultipartUnregistered (1.75s)986=== CONT TestReadProxyContentNegotiation9872026/10/25 13:22:20 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/25 13:22:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9892026/10/25 13:22:21 INFO Received uploads request method=POST path=/api/pending_closures990--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.36s)991=== CONT TestReadProxyNarinfoAlreadyDecompressed9922026/10/25 13:22:21 INFO Received cleanup request method=DELETE path=/api/pending_closures9932026/10/25 13:22:21 INFO Aborted multipart uploads count=0 kept=09942026/10/25 13:22:21 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/25 13:22:21 INFO Received cleanup request method=DELETE path=/api/pending_closures9962026/10/25 13:22:21 INFO Aborted multipart uploads count=1 kept=09972026/10/25 13:22:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9982026-10-25 13:22:21.547 UTC [29811] ERROR: Closure does not exist: id=19992026-10-25 13:22:21.547 UTC [29811] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10002026-10-25 13:22:21.547 UTC [29811] STATEMENT: -- name: CommitPendingClosure :one1001 SELECT commit_pending_closure($1::bigint)::bigint1002 1003--- PASS: TestService_cleanupPendingClosuresHandler (2.72s)1004=== CONT TestObjectStatsTrigger1005--- PASS: TestReadProxyHead (2.99s)1006=== CONT TestPushDedupSurvivesConcurrentGC10072026/10/25 13:22:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/10/25 13:22:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10092026/10/25 13:22:22 INFO Received uploads request method=POST path=/api/pending_closures10102026/10/25 13:22:22 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjcxNTA3NjliLTA5MWItNDA4Yi1iMDgwLWI3ZWUxNjY2MDZiOHgxNzkyOTM0NTM5ODMyNjEwMDAw parts=1210112026/10/25 13:22:22 INFO Received uploads request method=POST path=/api/pending_closures1012--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.36s)1013=== CONT TestService_NativeMTLS1014--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.44s)1015=== CONT TestGenerateLandingPage1016--- PASS: TestGenerateLandingPage (0.00s)1017=== CONT TestMetricsCommit10182026/10/25 13:22:22 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjAyYWQ3NWUwLWI3ZTMtNGIyZi05NzZjLWNhZmViNjU4MGYyZHgxNzkyOTM0NTQwMTExMzA5MDAw parts=1010192026/10/25 13:22:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10202026/10/25 13:22:22 INFO Completed upload id=1 objects=2 duration=16.199375ms10212026/10/25 13:22:22 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010222026/10/25 13:22:22 INFO Received uploads request method=POST path=/api/pending_closures10232026/10/25 13:22:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures10242026/10/25 13:22:22 INFO Aborted multipart uploads count=0 kept=010252026/10/25 13:22:22 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=010262026/10/25 13:22:22 INFO Vacuumed table table=pending_closures10272026/10/25 13:22:22 INFO Vacuumed table table=pending_objects10282026/10/25 13:22:22 INFO Vacuumed table table=multipart_uploads10292026/10/25 13:22:22 INFO Vacuumed table table=closures10302026/10/25 13:22:22 INFO Vacuumed table table=objects10312026/10/25 13:22:22 INFO Received push request method=POST path=/api/pushes10322026/10/25 13:22:22 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001033--- PASS: TestService_createPendingClosureHandler (3.71s)1034=== CONT TestPendingCleanupUsesOneCutoff10352026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10362026/10/25 13:22:22 INFO Signed narinfos id=1 count=110372026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10382026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10392026/10/25 13:22:22 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10402026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10412026/10/25 13:22:22 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10422026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10432026/10/25 13:22:22 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110442026/10/25 13:22:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10452026/10/25 13:22:22 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1046--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.76s)1047=== CONT TestMetricsInventory1048=== RUN TestPush_RejectsBadRequests/no_roots1049=== PAUSE TestPush_RejectsBadRequests/no_roots1050=== RUN TestPush_RejectsBadRequests/no_objects1051=== PAUSE TestPush_RejectsBadRequests/no_objects1052=== RUN TestPush_RejectsBadRequests/bad_root1053=== PAUSE TestPush_RejectsBadRequests/bad_root1054=== RUN TestPush_RejectsBadRequests/root_not_in_objects1055=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1056=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10572026/10/25 13:22:23 INFO Received uploads request method=POST path=/api/pending_closures1058--- PASS: TestService_Rustfstest (4.55s)1059=== CONT TestMultipartCleanup10602026/10/25 13:22:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1061--- PASS: TestReadProxy404 (4.95s)1062=== CONT TestServerTLSConfig1063=== RUN TestServerTLSConfig/no_client_CA1064=== PAUSE TestServerTLSConfig/no_client_CA1065=== RUN TestServerTLSConfig/missing_CA_file1066=== PAUSE TestServerTLSConfig/missing_CA_file1067=== RUN TestServerTLSConfig/not_a_PEM_file1068=== PAUSE TestServerTLSConfig/not_a_PEM_file1069=== CONT TestReadRedirectUsesPublicS3URL1070--- PASS: TestPresentRefreshesOnlyStaleClosures (5.46s)1071=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1072--- PASS: TestReadProxyInvalidPath (5.72s)1073=== CONT TestPush_RootsAreLockedInByteOrder1074--- PASS: TestReadProxyNarStreaming (6.07s)1075=== CONT TestService_readinessHandler1076=== NAME TestOrphanedObjectsGC1077 orphaned_objects_gc_test.go:287: GC Test Summary:1078 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1079 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1080 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1081 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1082 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1083--- PASS: TestOrphanedObjectsGC (6.23s)1084=== CONT TestPush_CompleteWaitsForCleanupOfThePush1085--- PASS: TestPresentReportsOnlyClosureRoots (6.69s)1086=== CONT TestService_healthCheckHandler10872026/10/25 13:22:26 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1088--- PASS: TestReadProxyNarinfo (7.22s)1089=== CONT TestPush_RepeatedRootCommitsOnce10902026/10/25 13:22:26 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/25 13:22:26 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/25 13:22:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10932026/10/25 13:22:26 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjg0MmMzNjQ4LTRhMDYtNDc2YS1iOGRlLTkxODMwMDNmZTlkN3gxNzkyOTM0NTQ2NDM1NTMyMDAw10942026/10/25 13:22:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjg0MmMzNjQ4LTRhMDYtNDc2YS1iOGRlLTkxODMwMDNmZTlkN3gxNzkyOTM0NTQ2NDM1NTMyMDAw parts=11095--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.01s)1096=== CONT TestNARDeduplicationMetadataUploadBug10972026/10/25 13:22:26 INFO Received uploads request method=POST path=/api/pending_closures10982026/10/25 13:22:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10992026/10/25 13:22:27 WARN Refused reserved pin name=worker-x86_64-linux11002026/10/25 13:22:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11012026/10/25 13:22:27 INFO Received create pin request method=POST path=/api/pins/my-app11022026/10/25 13:22:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1103--- PASS: TestCreatePin_ReservedPins (8.36s)1104=== CONT TestGracefulShutdownDrainsInflight11052026/10/25 13:22:27 INFO Starting HTTP server address=127.0.0.1:5734811062026/10/25 13:22:27 INFO Shutdown signal received, draining in-flight requests timeout=10s1107--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1108=== CONT TestPush_CompleteCommitsEveryRoot11092026/10/25 13:22:27 INFO Received uploads request method=POST path=/api/pending_closures1110--- PASS: TestReadProxyContentNegotiation (7.78s)1111=== CONT TestCreatePendingClosureRejectsOversizedNAR11122026/10/25 13:22:28 INFO Received uploads request method=POST path=/api/pending_closures1113--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1114=== CONT TestGCTaskStore_Fail1115--- PASS: TestGCTaskStore_Fail (0.00s)1116=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11172026/10/25 13:22:28 WARN Rate limiter enabled after throttle name=s3-test rate=511182026/10/25 13:22:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1119=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1120 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101121 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001122--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (9.80s)1123=== CONT TestSweepRechecksPendingAfterLocking1124--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.51s)1125=== CONT TestGCTaskStore_PhaseUpdates1126--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1127=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1128--- PASS: TestObjectStatsTrigger (7.69s)1129=== CONT TestForceGCDuringPushOffersSweptObject1130=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1131=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1132=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1133=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1134=== CONT TestGCTaskStore_CompletedAllowsNewTask1135--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1136=== CONT TestGCTaskStore_GetReturnsLatest1137--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1138=== CONT TestGCTaskStore_GetEmpty1139--- PASS: TestGCTaskStore_GetEmpty (0.00s)1140=== CONT TestGCSweepDeliversEachKeyOnce11412026/10/25 13:22:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/10/25 13:22:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjhjMjA4MzJhLTI1MjYtNGExOS04ZGE0LTYzY2UwYTE0ODhlYXgxNzkyOTM0NTQ2ODEwNjE1MDAw parts=1211432026/10/25 13:22:29 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/25 13:22:29 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/25 13:22:29 INFO Received uploads request method=POST path=/api/pending_closures11462026/10/25 13:22:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11472026/10/25 13:22:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1148--- PASS: TestService_NativeMTLS (7.91s)1149=== CONT TestGetExistingObjectsLocksRows11502026/10/25 13:22:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11512026/10/25 13:22:30 INFO Aborted multipart uploads count=0 kept=011522026/10/25 13:22:30 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=011532026/10/25 13:22:30 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLmJkOTRkZDUyLTU1YTUtNDVjZS1iMjJjLTJkMmM2YjdjMTYxMngxNzkyOTM0NTQ3NjU0NzM3MDAw parts=1011542026/10/25 13:22:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11552026/10/25 13:22:30 INFO Completed upload id=1 objects=2 duration=43.296791ms11562026/10/25 13:22:30 INFO Vacuumed table table=pending_closures11572026/10/25 13:22:30 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/25 13:22:30 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/25 13:22:30 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11602026/10/25 13:22:30 WARN Found objects in DB but missing from S3, will re-upload count=11161--- PASS: TestService_verifyS3Integrity (10.93s)1162=== CONT TestGCTaskStore_ConflictDifferentParams1163--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1164=== CONT TestTombstonedObjectOfferedWithoutWaiting11652026/10/25 13:22:30 INFO Vacuumed table table=pending_objects11662026/10/25 13:22:30 INFO Vacuumed table table=multipart_uploads11672026/10/25 13:22:30 INFO Vacuumed table table=closures11682026/10/25 13:22:30 INFO Vacuumed table table=objects11692026/10/25 13:22:30 INFO Aborted multipart uploads count=0 kept=011702026/10/25 13:22:30 WARN Force mode enabled - objects will be deleted immediately without grace period11712026/10/25 13:22:30 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=011722026/10/25 13:22:30 INFO Vacuumed table table=pending_closures11732026/10/25 13:22:30 INFO Vacuumed table table=pending_objects11742026/10/25 13:22:30 INFO Received push request method=POST path=/api/pushes11752026/10/25 13:22:30 INFO Vacuumed table table=multipart_uploads11762026/10/25 13:22:30 INFO Vacuumed table table=closures11772026/10/25 13:22:30 INFO Vacuumed table table=objects1178--- PASS: TestPushDedupSurvivesConcurrentGC (8.84s)1179=== CONT TestRegisterCompletedObjectNeedsPendingRow11802026/10/25 13:22:30 INFO Received complete push request method=POST path=/api/pushes/1/complete11812026/10/25 13:22:30 INFO Completed push id=1 objects=4 duration=51.117ms11822026/10/25 13:22:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11832026/10/25 13:22:30 INFO Completed upload id=2 objects=2 duration=884µs1184--- PASS: TestMetricsCommit (8.68s)1185=== CONT TestGCTaskStore_DeduplicateSameParams1186--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1187=== CONT TestGCSweepSkipsPendingObjects11882026/10/25 13:22:31 INFO Received uploads request method=POST path=/api/pending_closures11892026/10/25 13:22:31 INFO Received uploads request method=POST path=/api/pending_closures11902026/10/25 13:22:31 INFO Received cleanup request method=DELETE path=/api/pending_closures1191--- PASS: TestMetricsInventory (9.15s)1192=== CONT TestSweepSkipsRowsLockedByPush11932026/10/25 13:22:32 INFO Received uploads request method=POST path=/api/pending_closures1194--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (9.46s)1195=== CONT TestGCTaskStore_StartNew1196--- PASS: TestGCTaskStore_StartNew (0.00s)1197=== CONT TestDeduplicatedObjectsRecordedAsPending11982026/10/25 13:22:32 INFO Received uploads request method=POST path=/api/pending_closures11992026/10/25 13:22:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12002026/10/25 13:22:32 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjk5MDAwZjU1LTg3MGMtNDVkYy05ZWU4LTVhMjVlMTZkYzAyOXgxNzkyOTM0NTQ5ODg4NjIyMDAw error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12012026/10/25 13:22:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGU3MTRlMmEtZDc2ZS00NzQ0LTljOWUtYjdjZjQ2OGNhZjZlLjBjNjA2YTFiLWE2ZGEtNGYxNC05ZjcwLTk5ZjQyNDFkNzg1MngxNzkyOTM0NTQ5ODExNTgyMDAw parts=1212022026/10/25 13:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures12032026/10/25 13:22:32 INFO Aborted multipart uploads count=1 kept=01204--- PASS: TestRedundantMultipartUpload (13.94s)1205=== CONT TestFailedS3DeleteKeepsTombstone12062026/10/25 13:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures12072026/10/25 13:22:32 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12082026/10/25 13:22:32 INFO Aborted multipart uploads count=0 kept=112092026/10/25 13:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures12102026/10/25 13:22:32 INFO Aborted multipart uploads count=1 kept=01211--- PASS: TestMultipartCleanup (9.60s)1212=== CONT TestGCEndsOnShutdown1213=== RUN TestGCEndsOnShutdown/before_the_run1214=== PAUSE TestGCEndsOnShutdown/before_the_run1215=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1216=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1217=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1218=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1219=== CONT TestConnectWaitsForAPeerMigration1220--- PASS: TestReadRedirectUsesPublicS3URL (9.34s)1221=== CONT TestCommitRacingPendingCleanupKeepsObjects12222026/10/25 13:22:33 INFO Received push request method=POST path=/api/pushes12232026/10/25 13:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete12242026/10/25 13:22:33 INFO Completed push id=1 objects=4 duration=45.1525ms12252026/10/25 13:22:33 INFO Received push request method=POST path=/api/pushes12262026/10/25 13:22:33 INFO Aborted multipart uploads count=0 kept=012272026/10/25 13:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/25 13:22:33 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=012292026/10/25 13:22:33 INFO Received push request method=POST path=/api/pushes12302026/10/25 13:22:33 INFO Vacuumed table table=pending_closures12312026/10/25 13:22:34 INFO Vacuumed table table=pending_objects12322026/10/25 13:22:34 INFO Vacuumed table table=multipart_uploads12332026/10/25 13:22:34 INFO Vacuumed table table=closures12342026-10-25 13:22:34.280 UTC [29936] ERROR: could not obtain lock on row in relation "closures"12352026-10-25 13:22:34.280 UTC [29936] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12362026-10-25 13:22:34.286 UTC [29936] ERROR: could not obtain lock on row in relation "closures"12372026-10-25 13:22:34.286 UTC [29936] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12382026/10/25 13:22:34 INFO Vacuumed table table=objects12392026-10-25 13:22:34.294 UTC [29936] ERROR: could not obtain lock on row in relation "closures"12402026-10-25 13:22:34.294 UTC [29936] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12412026-10-25 13:22:34.296 UTC [29936] ERROR: could not obtain lock on row in relation "closures"12422026-10-25 13:22:34.296 UTC [29936] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12432026/10/25 13:22:34 INFO Received complete push request method=POST path=/api/pushes/2/complete12442026-10-25 13:22:34.303 UTC [29936] ERROR: could not obtain lock on row in relation "closures"12452026-10-25 13:22:34.303 UTC [29936] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12462026/10/25 13:22:34 INFO Completed push id=2 objects=4 duration=11.839083ms1247--- PASS: TestPush_RootsAreLockedInByteOrder (9.74s)1248--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (9.99s)1249=== CONT TestGCMetrics1250=== CONT TestPushWaitsForSweepHoldingRow12512026/10/25 13:22:34 WARN readiness check failed error="closed pool"1252--- PASS: TestService_readinessHandler (9.50s)1253=== CONT TestGCBugBareHashReferences12542026/10/25 13:22:34 INFO Received push request method=POST path=/api/pushes12552026-10-25 13:22:35.351 UTC [29946] ERROR: Push does not exist: id=112562026-10-25 13:22:35.351 UTC [29946] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12572026-10-25 13:22:35.351 UTC [29946] STATEMENT: SELECT commit_push($1)1258--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (10.26s)1259=== CONT TestClientSharedPathCommittedMidPush1260--- PASS: TestService_healthCheckHandler (9.82s)1261=== CONT TestDeleteClosuresRacingPins12622026/10/25 13:22:35 INFO Received push request method=POST path=/api/pushes12632026/10/25 13:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete12642026/10/25 13:22:36 INFO Completed push id=1 objects=4 duration=56.673834ms1265--- PASS: TestPush_RepeatedRootCommitsOnce (10.09s)1266=== CONT TestClientFallsBackToClosures1267=== NAME TestObjectStatsLargeCommit1268 object_stats_test.go:99: committing 60000 objects took 9.543904917s1269--- FAIL: TestObjectStatsLargeCommit (17.40s)1270=== CONT TestResolveDBConnectionString1271=== RUN TestResolveDBConnectionString/flag_wins1272=== PAUSE TestResolveDBConnectionString/flag_wins1273=== RUN TestResolveDBConnectionString/file_when_flag_empty1274=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1275=== RUN TestResolveDBConnectionString/missing_file_is_an_error1276=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1277=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1278=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1279=== RUN TestResolveDBConnectionString/nothing_configured1280=== PAUSE TestResolveDBConnectionString/nothing_configured1281=== CONT TestClientPushesUseOnePush12822026/10/25 13:22:36 INFO Received push request method=POST path=/api/pushes12832026/10/25 13:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete1284=== NAME TestNARDeduplicationMetadataUploadBug1285 metadata_upload_test.go:48: First store path: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestNARDeduplicationMetadataUploadBug408076242/001/store/1v50fcf8p8alci3jdcyv926sl92aa4h6-file1.txt12862026/10/25 13:22:36 INFO Completed push id=1 objects=6 duration=51.909083ms1287--- PASS: TestPush_CompleteCommitsEveryRoot (9.63s)1288=== CONT TestPinProtectsFromGC12892026/10/25 13:22:37 INFO Received push request method=POST path=/api/pushes12902026/10/25 13:22:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12912026/10/25 13:22:37 INFO Uploading 1v50fcf8p8alci3jdcyv926sl92aa4h6-file1.txt (160B)12922026/10/25 13:22:37 INFO Received push request method=POST path=/api/pushes12932026/10/25 13:22:37 WARN Failed to register uploaded object key=1v50fcf8p8alci3jdcyv926sl92aa4h6.ls error="server returned 404: 404 page not found\n"12942026/10/25 13:22:37 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12952026/10/25 13:22:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12962026/10/25 13:22:37 INFO Signed narinfos id=1 count=112972026/10/25 13:22:37 INFO Uploading 1 narinfos12982026/10/25 13:22:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12992026/10/25 13:22:37 WARN Failed to register uploaded object key=1v50fcf8p8alci3jdcyv926sl92aa4h6.narinfo error="server returned 404: 404 page not found\n"13002026/10/25 13:22:37 INFO Aborted multipart uploads count=1 kept=01301--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (8.97s)1302=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13032026/10/25 13:22:37 INFO Completed push id=1 objects=3 duration=58.609666ms13042026/10/25 13:22:37 INFO Upload complete. (375ms)1305=== NAME TestNARDeduplicationMetadataUploadBug1306 metadata_upload_test.go:54: Retrieved narinfo from S3:1307 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestNARDeduplicationMetadataUploadBug408076242/001/store/1v50fcf8p8alci3jdcyv926sl92aa4h6-file1.txt1308 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1309 Compression: zstd1310 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1311 NarSize: 1601312 References: 1313 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1314 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)13152026/10/25 13:22:37 INFO Received cleanup request method=DELETE path=/api/pending_closures1316 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1317 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13182026/10/25 13:22:37 INFO Aborted multipart uploads count=1 kept=01319--- PASS: TestPendingCleanupUsesOneCutoff (14.87s)1320=== CONT TestGCAdvisoryLockBlocksConcurrentRun1321=== NAME TestNARDeduplicationMetadataUploadBug1322 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestNARDeduplicationMetadataUploadBug408076242/001/store/rw2rw5scmccr34iggqc10jrf6m7xbn6l-file2.txt13232026/10/25 13:22:37 INFO Aborted multipart uploads count=0 kept=013242026/10/25 13:22:37 INFO Received push request method=POST path=/api/pushes13252026/10/25 13:22:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13262026/10/25 13:22:37 WARN Force mode enabled - objects will be deleted immediately without grace period13272026/10/25 13:22:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013282026/10/25 13:22:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13292026/10/25 13:22:37 WARN Failed to register uploaded object key=rw2rw5scmccr34iggqc10jrf6m7xbn6l.ls error="server returned 404: 404 page not found\n"13302026/10/25 13:22:37 INFO Signed narinfos id=2 count=113312026/10/25 13:22:37 INFO Uploading 1 narinfos13322026/10/25 13:22:37 INFO Vacuumed table table=pending_closures13332026/10/25 13:22:37 INFO Received complete push request method=POST path=/api/pushes/2/complete13342026/10/25 13:22:37 WARN Failed to register uploaded object key=rw2rw5scmccr34iggqc10jrf6m7xbn6l.narinfo error="server returned 404: 404 page not found\n"13352026/10/25 13:22:37 INFO Vacuumed table table=pending_objects13362026/10/25 13:22:37 INFO Completed push id=2 objects=3 duration=11.329917ms13372026/10/25 13:22:37 INFO Upload complete. (223ms)1338 metadata_upload_test.go:76: Retrieved narinfo from S3:1339 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestNARDeduplicationMetadataUploadBug408076242/001/store/rw2rw5scmccr34iggqc10jrf6m7xbn6l-file2.txt1340 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1341 Compression: zstd1342 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1343 NarSize: 1601344 References: 1345 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1346 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1347 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1348 {"version":1,"root":{"type":"regular","size":44}}13492026/10/25 13:22:37 INFO Vacuumed table table=multipart_uploads13502026/10/25 13:22:37 INFO Vacuumed table table=closures13512026/10/25 13:22:37 INFO Vacuumed table table=objects1352--- PASS: TestSweepRechecksPendingAfterLocking (9.25s)1353=== CONT TestLeadEndsOnShutdown13542026/10/25 13:22:37 INFO Received uploads request method=POST path=/api/pending_closures1355--- PASS: TestNARDeduplicationMetadataUploadBug (11.11s)1356=== CONT TestLeadIncumbentAnnouncesAtOnce1357--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (9.49s)1358=== CONT TestLeadElectsOneAndHandsOver13592026/10/25 13:22:38 INFO Aborted multipart uploads count=0 kept=013602026/10/25 13:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period1361--- PASS: TestGetExistingObjectsLocksRows (8.73s)1362=== CONT TestClientWithDependencies13632026/10/25 13:22:38 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=013642026/10/25 13:22:38 INFO Vacuumed table table=pending_closures13652026/10/25 13:22:38 INFO Vacuumed table table=pending_objects13662026/10/25 13:22:38 INFO Vacuumed table table=multipart_uploads13672026/10/25 13:22:38 INFO Vacuumed table table=closures13682026/10/25 13:22:38 INFO Vacuumed table table=objects1369--- PASS: TestGCSweepDeliversEachKeyOnce (9.72s)1370=== CONT TestCacheConfigHandler1371=== RUN TestCacheConfigHandler/full_config,_no_issuer1372=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1373=== RUN TestCacheConfigHandler/no_cache_url_configured1374=== PAUSE TestCacheConfigHandler/no_cache_url_configured1375=== RUN TestCacheConfigHandler/no_signing_keys1376=== PAUSE TestCacheConfigHandler/no_signing_keys1377=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1378=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1379=== CONT TestService_AuthMiddleware_OIDC13802026/10/25 13:22:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57462/oidc13812026/10/25 13:22:39 INFO Received uploads request method=POST path=/api/pending_closures1382--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.90s)1383=== CONT TestService_ReadScope_PublicByDefault1384--- PASS: TestRegisterCompletedObjectNeedsPendingRow (8.99s)1385=== CONT TestClientIntegration13862026/10/25 13:22:40 INFO Received uploads request method=POST path=/api/pending_closures13872026/10/25 13:22:40 INFO Aborted multipart uploads count=0 kept=013882026/10/25 13:22:40 WARN Force mode enabled - objects will be deleted immediately without grace period13892026/10/25 13:22: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=013902026/10/25 13:22:40 INFO Vacuumed table table=pending_closures13912026/10/25 13:22:40 INFO Vacuumed table table=pending_objects13922026/10/25 13:22:40 INFO Vacuumed table table=multipart_uploads13932026/10/25 13:22:40 INFO Vacuumed table table=closures13942026/10/25 13:22:40 INFO Vacuumed table table=objects1395--- PASS: TestGCSweepSkipsPendingObjects (9.57s)1396=== CONT TestService_RequireScope_OIDC13972026/10/25 13:22:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57472/oidc13982026/10/25 13:22:40 INFO Aborted multipart uploads count=0 kept=013992026/10/25 13:22:40 WARN Force mode enabled - objects will be deleted immediately without grace period14002026/10/25 13:22: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=014012026/10/25 13:22:40 INFO Vacuumed table table=pending_closures14022026/10/25 13:22:40 INFO Vacuumed table table=pending_objects14032026/10/25 13:22:40 INFO Vacuumed table table=multipart_uploads14042026/10/25 13:22:40 INFO Vacuumed table table=closures14052026/10/25 13:22:40 INFO Vacuumed table table=objects14062026/10/25 13:22:40 INFO Aborted multipart uploads count=0 kept=014072026/10/25 13:22:40 WARN Force mode enabled - objects will be deleted immediately without grace period14082026/10/25 13:22:40 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=014092026/10/25 13:22:40 INFO Vacuumed table table=pending_closures14102026/10/25 13:22:40 INFO Vacuumed table table=pending_objects14112026/10/25 13:22:40 INFO Vacuumed table table=multipart_uploads14122026/10/25 13:22:40 INFO Vacuumed table table=closures14132026/10/25 13:22:40 INFO Vacuumed table table=objects1414--- PASS: TestSweepSkipsRowsLockedByPush (9.22s)1415=== CONT TestClientErrorHandling1416=== RUN TestClientErrorHandling/InvalidStorePath14172026/10/25 13:22:40 INFO Received uploads request method=POST path=/api/pending_closures1418=== PAUSE TestClientErrorHandling/InvalidStorePath1419=== RUN TestClientErrorHandling/InvalidAuthToken1420=== PAUSE TestClientErrorHandling/InvalidAuthToken1421=== RUN TestClientErrorHandling/ServerNotAvailable1422=== PAUSE TestClientErrorHandling/ServerNotAvailable1423=== CONT TestClientMultipleUploads1424--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.67s)1425=== CONT TestClientCADerivations14262026/10/25 13:22:41 INFO Received uploads request method=POST path=/api/pending_closures14272026/10/25 13:22:41 INFO Aborted multipart uploads count=0 kept=014282026/10/25 13:22:41 WARN Force mode enabled - objects will be deleted immediately without grace period14292026/10/25 13:22:41 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14302026/10/25 13:22:41 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1431--- PASS: TestFailedS3DeleteKeepsTombstone (9.00s)1432=== CONT TestReadProxyDisabled14332026/10/25 13:22:42 INFO Aborted multipart uploads count=0 kept=01434=== NAME TestOrphanedObjectsGCStressTest1435 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14362026/10/25 13:22:42 WARN Force mode enabled - objects will be deleted immediately without grace period14372026/10/25 13:22:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014382026/10/25 13:22:42 INFO Vacuumed table table=pending_closures1439 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion14402026/10/25 13:22:42 INFO Vacuumed table table=pending_objects14412026/10/25 13:22:42 INFO Vacuumed table table=multipart_uploads14422026/10/25 13:22:42 INFO Aborted multipart uploads count=0 kept=014432026/10/25 13:22:42 WARN Force mode enabled - objects will be deleted immediately without grace period14442026/10/25 13:22:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014452026/10/25 13:22:42 INFO Vacuumed table table=pending_closures14462026/10/25 13:22:42 INFO Vacuumed table table=pending_objects14472026/10/25 13:22:42 INFO Vacuumed table table=multipart_uploads14482026/10/25 13:22:42 INFO Vacuumed table table=closures14492026/10/25 13:22:42 INFO Vacuumed table table=objects1450--- PASS: TestGCMetrics (8.14s)1451=== CONT TestCacheStatsHandler14522026/10/25 13:22:42 INFO Vacuumed table table=closures14532026/10/25 13:22:42 INFO Vacuumed table table=objects1454--- PASS: TestCommitRacingPendingCleanupKeepsObjects (9.35s)1455=== CONT TestReadProxyConditionalGet1456--- PASS: TestConnectWaitsForAPeerMigration (9.81s)1457=== CONT TestReadProxyRangeRequest1458--- PASS: TestGCBugBareHashReferences (8.59s)1459=== CONT TestReadRedirectKeepsNarinfoProxied14602026/10/25 13:22:43 INFO Received uploads request method=POST path=/api/pending_closures1461--- PASS: TestPushWaitsForSweepHoldingRow (9.34s)1462=== CONT TestReadProxyRootRedirectsToIndexHTML14632026/10/25 13:22:44 INFO Received push request method=POST path=/api/pushes14642026/10/25 13:22:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14652026/10/25 13:22:44 INFO Uploading sqjq6adbjiqb7khdjsmj4801xznc76yg-top (264B)14662026/10/25 13:22:44 INFO Uploading 9k26pmkrw622y0rf1sp1z6ghgaf3si7y-shared-dep (136B)14672026/10/25 13:22:44 WARN Failed to register uploaded object key=sqjq6adbjiqb7khdjsmj4801xznc76yg.ls error="server returned 404: 404 page not found\n"14682026/10/25 13:22:44 WARN Failed to register uploaded object key=9k26pmkrw622y0rf1sp1z6ghgaf3si7y.ls error="server returned 404: 404 page not found\n"14692026/10/25 13:22:44 WARN Failed to register uploaded object key=nar/0h7jpa02i5jwr17wylxdgy6pmkr6kqvr7fy1fc8m693jwbaijfhy.nar.zst error="server returned 404: 404 page not found\n"14702026/10/25 13:22:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14712026/10/25 13:22:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14722026/10/25 13:22:44 INFO Signed narinfos id=1 count=214732026/10/25 13:22:44 INFO Uploading 2 narinfos14742026/10/25 13:22:44 WARN Failed to register uploaded object key=9k26pmkrw622y0rf1sp1z6ghgaf3si7y.narinfo error="server returned 404: 404 page not found\n"14752026/10/25 13:22:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14762026/10/25 13:22:44 WARN Failed to register uploaded object key=sqjq6adbjiqb7khdjsmj4801xznc76yg.narinfo error="server returned 404: 404 page not found\n"14772026/10/25 13:22:44 INFO Completed push id=1 objects=6 duration=34.961667ms14782026/10/25 13:22:44 INFO Upload complete. (293ms)1479=== NAME TestClientSharedPathCommittedMidPush1480 client_integration_test.go:680: Retrieved narinfo from S3:1481 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientSharedPathCommittedMidPush2478733030/001/store/9k26pmkrw622y0rf1sp1z6ghgaf3si7y-shared-dep1482 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1483 Compression: zstd1484 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821485 NarSize: 1361486 References: 1487 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1488 client_integration_test.go:680: Retrieved narinfo from S3:1489 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientSharedPathCommittedMidPush2478733030/001/store/sqjq6adbjiqb7khdjsmj4801xznc76yg-top1490 URL: nar/0h7jpa02i5jwr17wylxdgy6pmkr6kqvr7fy1fc8m693jwbaijfhy.nar.zst1491 Compression: zstd1492 NarHash: sha256:0h7jpa02i5jwr17wylxdgy6pmkr6kqvr7fy1fc8m693jwbaijfhy1493 NarSize: 2641494 References: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientSharedPathCommittedMidPush2478733030/001/store/9k26pmkrw622y0rf1sp1z6ghgaf3si7y-shared-dep1495 CA: text:sha256:1whfjlsc5iw9vs7ya1vbi7jpmnrvvka5js338gd5kiv9qjb9xykn1496--- PASS: TestClientSharedPathCommittedMidPush (9.03s)1497=== CONT TestReadRedirectNar14982026/10/25 13:22:44 INFO Received uploads request method=POST path=/api/pending_closures14992026/10/25 13:22:44 INFO Received uploads request method=POST path=/api/pending_closures15002026/10/25 13:22:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15012026/10/25 13:22:44 INFO Uploading pc9cb3n4kv08amm9hzcdcllqng7z3l8d-b (256B)15022026/10/25 13:22:44 INFO Uploading bs1mprkaqdpnrfll8p6cvdshb8fc52a2-shared-dep (136B)15032026/10/25 13:22:44 WARN Failed to register uploaded object key=kkmc0xlkwrda26464c4b7jp4v56fyb2z.ls error="server returned 404: 404 page not found\n"15042026/10/25 13:22:44 WARN Failed to register uploaded object key=bs1mprkaqdpnrfll8p6cvdshb8fc52a2.ls error="server returned 404: 404 page not found\n"15052026/10/25 13:22:44 WARN Failed to register uploaded object key=pc9cb3n4kv08amm9hzcdcllqng7z3l8d.ls error="server returned 404: 404 page not found\n"15062026/10/25 13:22:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15072026/10/25 13:22:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15082026/10/25 13:22:44 WARN Failed to register uploaded object key=nar/0na2vqlhd0i2qwq3v4vr3zqqpvbji2jib5j2byrh2lkaivcagbqi.nar.zst error="server returned 404: 404 page not found\n"15092026/10/25 13:22:44 INFO Signed narinfos id=1 count=215102026/10/25 13:22:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15112026/10/25 13:22:44 INFO Signed narinfos id=2 count=215122026/10/25 13:22:44 INFO Uploading 4 narinfos15132026/10/25 13:22:44 INFO Received push request method=POST path=/api/pushes15142026/10/25 13:22:44 WARN Failed to register uploaded object key=kkmc0xlkwrda26464c4b7jp4v56fyb2z.narinfo error="server returned 404: 404 page not found\n"15152026/10/25 13:22:44 WARN Failed to register uploaded object key=bs1mprkaqdpnrfll8p6cvdshb8fc52a2.narinfo error="server returned 404: 404 page not found\n"15162026/10/25 13:22:44 WARN Failed to register uploaded object key=pc9cb3n4kv08amm9hzcdcllqng7z3l8d.narinfo error="server returned 404: 404 page not found\n"15172026/10/25 13:22:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15182026/10/25 13:22:44 INFO Uploading q0idw08l80czlab8nnk8bzy0s9qna6bp-shared-dep (136B)15192026/10/25 13:22:44 INFO Uploading 96kysx2cmg0cpz8mll0cj0sz42xg5wb7-a (256B)15202026/10/25 13:22:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15212026/10/25 13:22:45 WARN Failed to register uploaded object key=bs1mprkaqdpnrfll8p6cvdshb8fc52a2.narinfo error="server returned 404: 404 page not found\n"15222026/10/25 13:22:45 WARN Failed to register uploaded object key=96kysx2cmg0cpz8mll0cj0sz42xg5wb7.ls error="server returned 404: 404 page not found\n"15232026/10/25 13:22:45 INFO Completed upload id=1 objects=6 duration=33.501917ms15242026/10/25 13:22:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15252026/10/25 13:22:45 WARN Failed to register uploaded object key=2i67mjm3pm2gr6sqwmz28ciljh0vrxkr.ls error="server returned 404: 404 page not found\n"15262026/10/25 13:22:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15272026/10/25 13:22:45 INFO Completed upload id=2 objects=6 duration=414.291µs15282026/10/25 13:22:45 WARN Failed to register uploaded object key=nar/09l5ml787wqrjq294pyv25jdhr9xpwmsk7yvd0y470dggl6haj7g.nar.zst error="server returned 404: 404 page not found\n"15292026/10/25 13:22:45 INFO Upload complete. (415ms)1530=== NAME TestClientFallsBackToClosures1531 client_pushes_test.go:112: Retrieved narinfo from S3:1532 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientFallsBackToClosures2929709628/001/store/bs1mprkaqdpnrfll8p6cvdshb8fc52a2-shared-dep1533 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1534 Compression: zstd1535 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821536 NarSize: 1361537 References: 1538 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15392026/10/25 13:22:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1540 client_pushes_test.go:112: Retrieved narinfo from S3:1541 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientFallsBackToClosures2929709628/001/store/kkmc0xlkwrda26464c4b7jp4v56fyb2z-a1542 URL: nar/0na2vqlhd0i2qwq3v4vr3zqqpvbji2jib5j2byrh2lkaivcagbqi.nar.zst1543 Compression: zstd1544 NarHash: sha256:0na2vqlhd0i2qwq3v4vr3zqqpvbji2jib5j2byrh2lkaivcagbqi1545 NarSize: 2561546 References: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientFallsBackToClosures2929709628/001/store/bs1mprkaqdpnrfll8p6cvdshb8fc52a2-shared-dep1547 CA: text:sha256:19mkd5czzb4riy53y162qw8kqd5ifglf8v56drv858pf4427gnd215482026/10/25 13:22:45 WARN Failed to register uploaded object key=q0idw08l80czlab8nnk8bzy0s9qna6bp.ls error="server returned 404: 404 page not found\n"15492026/10/25 13:22:45 INFO Signed narinfos id=1 count=31550 client_pushes_test.go:112: Retrieved narinfo from S3:1551 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientFallsBackToClosures2929709628/001/store/pc9cb3n4kv08amm9hzcdcllqng7z3l8d-b1552 URL: nar/0na2vqlhd0i2qwq3v4vr3zqqpvbji2jib5j2byrh2lkaivcagbqi.nar.zst1553 Compression: zstd1554 NarHash: sha256:0na2vqlhd0i2qwq3v4vr3zqqpvbji2jib5j2byrh2lkaivcagbqi1555 NarSize: 2561556 References: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientFallsBackToClosures2929709628/001/store/bs1mprkaqdpnrfll8p6cvdshb8fc52a2-shared-dep1557 CA: text:sha256:19mkd5czzb4riy53y162qw8kqd5ifglf8v56drv858pf4427gnd215582026/10/25 13:22:45 INFO Uploading 3 narinfos15592026/10/25 13:22:45 WARN Failed to register uploaded object key=96kysx2cmg0cpz8mll0cj0sz42xg5wb7.narinfo error="server returned 404: 404 page not found\n"15602026/10/25 13:22:45 WARN Failed to register uploaded object key=2i67mjm3pm2gr6sqwmz28ciljh0vrxkr.narinfo error="server returned 404: 404 page not found\n"15612026/10/25 13:22:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15622026/10/25 13:22:45 WARN Failed to register uploaded object key=q0idw08l80czlab8nnk8bzy0s9qna6bp.narinfo error="server returned 404: 404 page not found\n"1563--- PASS: TestClientFallsBackToClosures (9.00s)1564=== CONT TestReadProxyOutlastsServerWriteTimeout15652026/10/25 13:22:45 INFO Completed push id=1 objects=8 duration=26.589292ms15662026/10/25 13:22:45 INFO Upload complete. (347ms)1567=== NAME TestClientPushesUseOnePush1568 client_pushes_test.go:97: Retrieved narinfo from S3:1569 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientPushesUseOnePush949600697/001/store/q0idw08l80czlab8nnk8bzy0s9qna6bp-shared-dep1570 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1571 Compression: zstd1572 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821573 NarSize: 1361574 References: 1575 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1576 client_pushes_test.go:97: Retrieved narinfo from S3:1577 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientPushesUseOnePush949600697/001/store/96kysx2cmg0cpz8mll0cj0sz42xg5wb7-a1578 URL: nar/09l5ml787wqrjq294pyv25jdhr9xpwmsk7yvd0y470dggl6haj7g.nar.zst1579 Compression: zstd1580 NarHash: sha256:09l5ml787wqrjq294pyv25jdhr9xpwmsk7yvd0y470dggl6haj7g1581 NarSize: 2561582 References: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientPushesUseOnePush949600697/001/store/q0idw08l80czlab8nnk8bzy0s9qna6bp-shared-dep1583 CA: text:sha256:04wx0ga9vxvy9mknb5fmxgqh0zy1y5m3y813085nb69b29sr98pq1584 client_pushes_test.go:97: Retrieved narinfo from S3:1585 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientPushesUseOnePush949600697/001/store/2i67mjm3pm2gr6sqwmz28ciljh0vrxkr-b1586 URL: nar/09l5ml787wqrjq294pyv25jdhr9xpwmsk7yvd0y470dggl6haj7g.nar.zst1587 Compression: zstd1588 NarHash: sha256:09l5ml787wqrjq294pyv25jdhr9xpwmsk7yvd0y470dggl6haj7g1589 NarSize: 2561590 References: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientPushesUseOnePush949600697/001/store/q0idw08l80czlab8nnk8bzy0s9qna6bp-shared-dep1591 CA: text:sha256:04wx0ga9vxvy9mknb5fmxgqh0zy1y5m3y813085nb69b29sr98pq1592=== NAME TestPinProtectsFromGC1593 client_integration_test.go:731: Pinned store path: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestPinProtectsFromGC2830260215/001/store/l65zscqslrddgyzpybv70w8qlss4wdqq-pinned-file.txt1594 client_integration_test.go:732: Unpinned store path: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestPinProtectsFromGC2830260215/001/store/j9j3m39x3z1lhcx9r50dmq8v6y3cadhm-unpinned-file.txt1595--- PASS: TestClientPushesUseOnePush (8.93s)1596=== CONT TestService_AuthMiddleware_MTLSProxyHeader15972026/10/25 13:22:45 INFO Received push request method=POST path=/api/pushes15982026/10/25 13:22:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15992026/10/25 13:22:45 INFO Uploading l65zscqslrddgyzpybv70w8qlss4wdqq-pinned-file.txt (128B)16002026/10/25 13:22:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16012026/10/25 13:22:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16022026/10/25 13:22:45 WARN Failed to register uploaded object key=l65zscqslrddgyzpybv70w8qlss4wdqq.ls error="server returned 404: 404 page not found\n"16032026/10/25 13:22:45 INFO Signed narinfos id=1 count=116042026/10/25 13:22:45 INFO Uploading 1 narinfos16052026/10/25 13:22:45 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1606--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.99s)1607=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16082026/10/25 13:22:45 INFO Received complete push request method=POST path=/api/pushes/1/complete16092026/10/25 13:22:45 WARN Failed to register uploaded object key=l65zscqslrddgyzpybv70w8qlss4wdqq.narinfo error="server returned 404: 404 page not found\n"16102026/10/25 13:22:45 INFO Completed push id=1 objects=3 duration=25.766458ms16112026/10/25 13:22:45 INFO Upload complete. (221ms)16122026/10/25 13:22:45 INFO Received push request method=POST path=/api/pushes16132026/10/25 13:22:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16142026/10/25 13:22:45 INFO Uploading j9j3m39x3z1lhcx9r50dmq8v6y3cadhm-unpinned-file.txt (128B)16152026/10/25 13:22:45 WARN Failed to register uploaded object key=j9j3m39x3z1lhcx9r50dmq8v6y3cadhm.ls error="server returned 404: 404 page not found\n"16162026/10/25 13:22:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16172026/10/25 13:22:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16182026/10/25 13:22:45 INFO Signed narinfos id=2 count=116192026/10/25 13:22:45 INFO Uploading 1 narinfos16202026/10/25 13:22:45 INFO lead: acquired remote=192.0.2.1:123416212026/10/25 13:22:45 INFO Received complete push request method=POST path=/api/pushes/2/complete16222026/10/25 13:22:45 WARN Failed to register uploaded object key=j9j3m39x3z1lhcx9r50dmq8v6y3cadhm.narinfo error="server returned 404: 404 page not found\n"16232026/10/25 13:22:45 INFO Completed push id=2 objects=3 duration=581.5µs16242026/10/25 13:22:45 INFO Upload complete. (164ms)16252026/10/25 13:22:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures16262026/10/25 13:22:45 INFO Garbage collection started16272026/10/25 13:22:45 INFO Aborted multipart uploads count=0 kept=016282026/10/25 13:22:45 WARN Force mode enabled - objects will be deleted immediately without grace period16292026/10/25 13:22:45 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=016302026/10/25 13:22:45 INFO Vacuumed table table=pending_closures16312026/10/25 13:22:45 INFO lead: acquired remote=192.0.2.1:123416322026/10/25 13:22:45 INFO lead: released remote=192.0.2.1:12341633--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.87s)1634=== CONT TestService_ReadAuthMiddleware16352026/10/25 13:22:45 INFO Vacuumed table table=pending_objects16362026/10/25 13:22:45 INFO Vacuumed table table=multipart_uploads16372026/10/25 13:22:45 INFO Vacuumed table table=closures16382026/10/25 13:22:45 INFO Vacuumed table table=objects1639--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.63s)1640=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16412026/10/25 13:22:45 INFO Received uploads request method=POST path=/1642=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16432026/10/25 13:22:45 INFO Received request for more parts method=POST path=/1644=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16452026/10/25 13:22:45 INFO Received complete multipart upload request method=POST path=/1646=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16472026/10/25 13:22:46 INFO lead: acquired remote=192.0.2.1:12341648=== NAME TestOrphanedObjectsGCStressTest1649 orphaned_objects_gc_test.go:503: Stress test completed successfully:1650 orphaned_objects_gc_test.go:504: - Active objects preserved: 201651 orphaned_objects_gc_test.go:505: - Objects deleted: 2101652 orphaned_objects_gc_test.go:506: - Total GC'd: 2101653--- PASS: TestOrphanedObjectsGCStressTest (27.63s)1654=== CONT TestProxyWriteTimeout/narinfo1655=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1656=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1657=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1658=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1659=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1660=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1661=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1662=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1663=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1664=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16652026/10/25 13:22:46 INFO Received uploads request method=POST path=/1666=== CONT TestProxyWriteTimeout/10_GiB_nar1667=== CONT TestPendingClosureWriteTimeout/empty1668=== CONT TestProxyWriteTimeout/1_GiB_nar1669=== CONT TestProxyWriteTimeout/unknown_size1670--- PASS: TestUploadHandlersRejectInvalidKeys (0.04s)1671 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1672 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1673 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1674 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1675=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1676--- PASS: TestProxyWriteTimeout (0.04s)1677 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1678 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1679 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1680 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)16812026/10/25 13:22:46 INFO lead: released remote=192.0.2.1:12341682--- PASS: TestLeadEndsOnShutdown (8.78s)1683=== CONT TestPendingClosureWriteTimeout/400_objects1684=== CONT TestPendingClosureWriteTimeout/670k_objects1685=== CONT TestParseSingleRange/none1686=== CONT TestParseSingleRange/end_clamped_to_size1687=== CONT TestParseSingleRange/open-ended1688=== CONT TestParseSingleRange/closed1689=== CONT TestParseSingleRange/malformed_end_before_start1690=== CONT TestParseSingleRange/malformed_both_empty1691=== CONT TestParseSingleRange/malformed_no_dash1692=== CONT TestParseSingleRange/multi-range_ignored1693=== CONT TestParseSingleRange/unknown_unit1694=== CONT TestParseSingleRange/single_byte1695=== CONT TestParseSingleRange/start_far_past_EOF1696=== CONT TestParseSingleRange/start_past_EOF1697=== CONT TestParseSingleRange/suffix_exceeds_size1698=== CONT TestParseSingleRange/suffix1699--- PASS: TestParseSingleRange (0.05s)1700 --- PASS: TestParseSingleRange/none (0.00s)1701 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1702 --- PASS: TestParseSingleRange/open-ended (0.00s)1703 --- PASS: TestParseSingleRange/closed (0.00s)1704 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1705 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1706 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1707 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1708 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1709 --- PASS: TestParseSingleRange/single_byte (0.00s)1710 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1711 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1712 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1713 --- PASS: TestParseSingleRange/suffix (0.00s)1714=== CONT TestIsValidCachePath/narinfo1715=== CONT TestIsValidCachePath/short_hash1716=== CONT TestIsValidCachePath/wrong_extension1717=== CONT TestIsValidCachePath/leading_slash1718=== CONT TestIsValidCachePath/empty1719=== CONT TestIsValidCachePath/random_path1720=== CONT TestIsValidCachePath/invalid_char_u1721=== CONT TestIsValidCachePath/invalid_char_e1722=== CONT TestIsValidCachePath/traversal_in_middle1723=== CONT TestIsValidCachePath/traversal_parent1724=== CONT TestIsValidCachePath/index.html1725=== CONT TestIsValidCachePath/nix-cache-info1726=== CONT TestIsValidCachePath/realisation1727=== CONT TestIsValidCachePath/log1728=== CONT TestIsValidCachePath/ls1729=== CONT TestIsValidCachePath/nar_uncompressed1730=== CONT TestIsValidCachePath/nar_bz21731=== CONT TestIsValidCachePath/nar_xz1732=== CONT TestIsValidCachePath/nar_zst1733=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1734--- PASS: TestIsValidCachePath (0.05s)1735 --- PASS: TestIsValidCachePath/narinfo (0.00s)1736 --- PASS: TestIsValidCachePath/short_hash (0.00s)1737 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1738 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1739 --- PASS: TestIsValidCachePath/empty (0.00s)1740 --- PASS: TestIsValidCachePath/random_path (0.00s)1741 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1742 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1743 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1744 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1745 --- PASS: TestIsValidCachePath/index.html (0.00s)1746 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1747 --- PASS: TestIsValidCachePath/realisation (0.00s)1748 --- PASS: TestIsValidCachePath/log (0.00s)1749 --- PASS: TestIsValidCachePath/ls (0.00s)1750 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1751 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1752 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1753 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1754 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1755=== CONT TestIsValidUploadKey/narinfo1756=== CONT TestIsValidUploadKey/realisation_plus_in_output1757=== CONT TestIsValidUploadKey/unknown_type1758=== CONT TestIsValidUploadKey/empty_key1759=== CONT TestIsValidUploadKey/absolute1760=== CONT TestIsValidUploadKey/traversal_nar1761=== CONT TestIsValidUploadKey/traversal1762=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1763=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1764=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1765=== CONT TestIsValidUploadKey/index.html1766=== CONT TestIsValidUploadKey/nix-cache-info1767=== CONT TestIsValidUploadKey/build_log_home-manager_file1768=== CONT TestIsValidUploadKey/realisation1769=== CONT TestIsValidUploadKey/build_log_equals1770=== CONT TestIsValidUploadKey/build_log_question_mark1771=== CONT TestIsValidUploadKey/build_log_plus_in_name1772=== CONT TestIsValidUploadKey/nar_plain1773=== CONT TestIsValidUploadKey/build_log1774=== CONT TestIsValidUploadKey/listing1775=== CONT TestIsValidUploadKey/nar_xz1776=== CONT TestIsValidUploadKey/nar_zst1777--- PASS: TestIsValidUploadKey (0.05s)1778 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1779 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1780 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1781 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1782 --- PASS: TestIsValidUploadKey/absolute (0.00s)1783 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1784 --- PASS: TestIsValidUploadKey/traversal (0.00s)1785 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1786 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1787 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1788 --- PASS: TestIsValidUploadKey/index.html (0.00s)1789 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1790 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1791 --- PASS: TestIsValidUploadKey/realisation (0.00s)1792 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1793 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1794 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1796 --- PASS: TestIsValidUploadKey/build_log (0.00s)1797 --- PASS: TestIsValidUploadKey/listing (0.00s)1798 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1799 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1800=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18012026/10/25 13:22:46 INFO Received uploads request method=POST path=/1802=== NAME TestClientWithDependencies1803 client_integration_test.go:613: Built derivation: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientWithDependencies3659980418/001/store/pr8q217hdzw583n2hj3dfjcxsqbf4l29-test-script1804--- PASS: TestService_ReadScope_PublicByDefault (7.62s)1805=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18062026/10/25 13:22:46 INFO Received request for more parts method=POST path=/1807=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18082026/10/25 13:22:46 INFO Received complete multipart upload request method=POST path=/1809=== CONT TestPush_RejectsBadRequests/no_roots18102026/10/25 13:22:46 INFO Received push request method=POST path=/api/pushes1811=== CONT TestPush_RejectsBadRequests/bad_root18122026/10/25 13:22:46 INFO Received push request method=POST path=/api/pushes1813=== CONT TestPush_RejectsBadRequests/root_not_in_objects18142026/10/25 13:22:46 INFO Received push request method=POST path=/api/pushes1815=== CONT TestPush_RejectsBadRequests/no_objects18162026/10/25 13:22:46 INFO Received push request method=POST path=/api/pushes1817--- PASS: TestPush_RejectsBadRequests (4.07s)1818 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1819 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1820 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1821 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1822=== CONT TestServerTLSConfig/no_client_CA1823=== NAME TestClientWithDependencies1824 client_integration_test.go:615: Found 1 dependencies (including self)1825=== CONT TestServerTLSConfig/not_a_PEM_file1826=== CONT TestServerTLSConfig/missing_CA_file1827--- PASS: TestServerTLSConfig (0.00s)1828 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1829 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1830 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1831=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1832--- PASS: TestUploadHandlersRejectOversizedBody (0.07s)1833 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1834 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1835 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1836=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18372026/10/25 13:22:47 INFO Received push request method=POST path=/api/pushes18382026/10/25 13:22:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18392026/10/25 13:22:47 INFO Uploading pr8q217hdzw583n2hj3dfjcxsqbf4l29-test-script (136B)18402026/10/25 13:22:47 WARN Failed to register uploaded object key=pr8q217hdzw583n2hj3dfjcxsqbf4l29.ls error="server returned 404: 404 page not found\n"18412026/10/25 13:22:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18422026/10/25 13:22:47 WARN Failed to register uploaded object key=log/viiwkxqwjf84l3j40h5nhj2fs75ky1yh-test-script.drv error="server returned 404: 404 page not found\n"18432026/10/25 13:22:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18442026/10/25 13:22:47 INFO Signed narinfos id=1 count=118452026/10/25 13:22:47 INFO Uploading 1 narinfos18462026/10/25 13:22:47 INFO Received complete push request method=POST path=/api/pushes/1/complete18472026/10/25 13:22:47 WARN Failed to register uploaded object key=pr8q217hdzw583n2hj3dfjcxsqbf4l29.narinfo error="server returned 404: 404 page not found\n"18482026/10/25 13:22:47 INFO Completed push id=1 objects=4 duration=18.040042ms18492026/10/25 13:22:47 INFO Upload complete. (274ms)1850=== NAME TestClientWithDependencies1851 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientWithDependencies3659980418/001/store) requires matching store prefix1852--- PASS: TestDeleteClosuresRacingPins (11.94s)18532026/10/25 13:22:47 INFO lead: released remote=192.0.2.1:12341854=== CONT TestGCEndsOnShutdown/before_the_run18552026/10/25 13:22:47 INFO lead: acquired remote=192.0.2.1:12341856--- PASS: TestClientWithDependencies (8.55s)1857=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1858=== NAME TestClientIntegration1859 client_integration_test.go:286: Created store path: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientIntegration447770566/002/store/khj42xib4msnim5z0nlv90fh3b5vk126-test-file.txt18602026/10/25 13:22:47 INFO Received push request method=POST path=/api/pushes18612026/10/25 13:22:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18622026/10/25 13:22:47 INFO Uploading khj42xib4msnim5z0nlv90fh3b5vk126-test-file.txt (152B)18632026/10/25 13:22:47 WARN Failed to register uploaded object key=khj42xib4msnim5z0nlv90fh3b5vk126.ls error="server returned 404: 404 page not found\n"18642026/10/25 13:22:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18652026/10/25 13:22:47 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18662026/10/25 13:22:47 INFO Signed narinfos id=1 count=118672026/10/25 13:22:47 INFO Uploading 1 narinfos18682026/10/25 13:22:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018692026/10/25 13:22:47 INFO Received create pin request method=POST path=/api/pins/myapp18702026/10/25 13:22:47 INFO Received complete push request method=POST path=/api/pushes/1/complete18712026/10/25 13:22:47 WARN Failed to register uploaded object key=khj42xib4msnim5z0nlv90fh3b5vk126.narinfo error="server returned 404: 404 page not found\n"18722026/10/25 13:22:47 INFO Completed push id=1 objects=3 duration=33.331334ms18732026/10/25 13:22:47 INFO Upload complete. (275ms)18742026/10/25 13:22:47 INFO Created/updated pin name=myapp store_path=/private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestPinProtectsFromGC2830260215/001/store/l65zscqslrddgyzpybv70w8qlss4wdqq-pinned-file.txt narinfo_key=l65zscqslrddgyzpybv70w8qlss4wdqq.narinfo18752026/10/25 13:22:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures18762026/10/25 13:22:47 INFO Garbage collection started18772026/10/25 13:22:47 INFO Aborted multipart uploads count=0 kept=018782026/10/25 13:22:47 WARN Force mode enabled - objects will be deleted immediately without grace period18792026/10/25 13:22: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=018802026/10/25 13:22:47 INFO Vacuumed table table=pending_closures18812026/10/25 13:22:47 INFO All 1 paths already cached18822026/10/25 13:22:47 INFO Vacuumed table table=pending_objects18832026/10/25 13:22:47 INFO Vacuumed table table=multipart_uploads1884=== RUN TestService_RequireScope_OIDC/builder_may_write1885=== PAUSE TestService_RequireScope_OIDC/builder_may_write1886=== RUN TestService_RequireScope_OIDC/builder_may_not_admin18872026/10/25 13:22:47 INFO Vacuumed table table=closures1888=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin18892026/10/25 13:22:47 INFO Vacuumed table table=objects1890=== NAME TestClientIntegration1891 client_integration_test.go:312: Retrieved narinfo from S3:1892 StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientIntegration447770566/002/store/khj42xib4msnim5z0nlv90fh3b5vk126-test-file.txt1893 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1894=== RUN TestService_RequireScope_OIDC/ops_may_admin1895=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1896=== RUN TestService_RequireScope_OIDC/ops_may_not_write1897=== NAME TestClientIntegration1898 Compression: zstd1899 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11900 NarSize: 1521901 References: 1902 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11903=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1904=== RUN TestService_RequireScope_OIDC/reader_may_not_write1905=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1906=== RUN TestService_RequireScope_OIDC/static_token_may_admin1907=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1908=== RUN TestService_RequireScope_OIDC/static_token_may_write1909=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1910=== RUN TestService_RequireScope_OIDC/reader_may_read1911=== PAUSE TestService_RequireScope_OIDC/reader_may_read1912=== NAME TestClientIntegration1913 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1914=== RUN TestService_RequireScope_OIDC/writer_implies_read1915=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1916=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1917=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1918=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1919=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1920=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1921=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1922=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1923=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1924=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1925=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1926=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1927=== NAME TestClientIntegration1928 client_integration_test.go:313: Decompressed .ls content (64 bytes):1929 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1930 client_integration_test.go:316: Testing garbage collection...19312026/10/25 13:22:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures19322026/10/25 13:22:47 INFO Garbage collection started19332026/10/25 13:22:47 INFO Aborted multipart uploads count=0 kept=019342026/10/25 13:22:47 WARN Force mode enabled - objects will be deleted immediately without grace period19352026/10/25 13:22:48 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=019362026/10/25 13:22:48 INFO Vacuumed table table=pending_closures19372026/10/25 13:22:48 INFO Vacuumed table table=pending_objects1938=== NAME TestClientCADerivations1939 client_ca_test.go:136: Built CA derivation: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientCADerivations2686859678/001/store/sswsz5fbdvswbh2pkwg95n8avsy62viz-ca-test19402026/10/25 13:22:48 INFO Vacuumed table table=multipart_uploads1941 client_ca_test.go:139: Found 1 dependencies (including self)19422026/10/25 13:22:48 INFO Vacuumed table table=closures19432026/10/25 13:22:48 INFO Vacuumed table table=objects19442026/10/25 13:22:48 INFO Received push request method=POST path=/api/pushes19452026/10/25 13:22:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1946=== NAME TestClientMultipleUploads1947 client_integration_test.go:358: Created store path 0: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientMultipleUploads452029581/001/store/6km423z0q8564j39hzh7yb5c7kgv9f93-test-file-0.txt19482026/10/25 13:22:48 INFO Uploading sswsz5fbdvswbh2pkwg95n8avsy62viz-ca-test (144B)1949--- PASS: TestReadProxyDisabled (6.59s)1950=== CONT TestResolveDBConnectionString/flag_wins1951=== CONT TestResolveDBConnectionString/missing_file_is_an_error19522026/10/25 13:22:48 INFO lead: released remote=192.0.2.1:12341953=== CONT TestResolveDBConnectionString/file_when_flag_empty1954--- PASS: TestLeadElectsOneAndHandsOver (10.23s)1955=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1956=== CONT TestResolveDBConnectionString/nothing_configured1957=== CONT TestCacheConfigHandler/full_config,_no_issuer1958=== CONT TestCacheConfigHandler/no_signing_keys1959=== CONT TestCacheConfigHandler/no_cache_url_configured1960=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator19612026/10/25 13:22:48 WARN Failed to register uploaded object key=sswsz5fbdvswbh2pkwg95n8avsy62viz.ls error="server returned 404: 404 page not found\n"1962--- PASS: TestCacheConfigHandler (0.01s)1963 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1964 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1965 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1966 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1967--- PASS: TestResolveDBConnectionString (0.06s)1968 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1969 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1970 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1971 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1972 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1973=== CONT TestClientErrorHandling/InvalidStorePath19742026/10/25 13:22:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1975=== CONT TestClientErrorHandling/ServerNotAvailable19762026/10/25 13:22:48 WARN Failed to register uploaded object key=log/b403my9ad05646bnk600g106wplp66mg-ca-test.drv error="server returned 404: 404 page not found\n"19772026/10/25 13:22:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19782026/10/25 13:22:48 INFO Signed narinfos id=1 count=119792026/10/25 13:22:48 INFO Uploading 1 narinfos19802026/10/25 13:22:48 INFO Received complete push request method=POST path=/api/pushes/1/complete19812026/10/25 13:22:48 WARN Failed to register uploaded object key=sswsz5fbdvswbh2pkwg95n8avsy62viz.narinfo error="server returned 404: 404 page not found\n"1982=== NAME TestClientMultipleUploads1983 client_integration_test.go:358: Created store path 1: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientMultipleUploads452029581/001/store/ab05xhb7if80w2waa1y1w42achlxxl2d-test-file-1.txt19842026/10/25 13:22:48 INFO Completed push id=1 objects=4 duration=22.554542ms19852026/10/25 13:22:48 INFO Upload complete. (364ms)1986=== NAME TestClientCADerivations1987 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientCADerivations2686859678/001/store/sswsz5fbdvswbh2pkwg95n8avsy62viz-ca-test1988 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1989 Compression: zstd1990 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1991 NarSize: 1441992 References: 1993 Deriver: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientCADerivations2686859678/001/store/b403my9ad05646bnk600g106wplp66mg-ca-test.drv1994 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1995 client_ca_test.go:185: Checking for realisation files in S3...1996 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1997 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1998=== NAME TestClientMultipleUploads1999 client_integration_test.go:358: Created store path 2: /private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientMultipleUploads452029581/001/store/vbqj3ds2izs1g4vbr565m2gqyj0is2id-test-file-2.txt2000=== NAME TestClientCADerivations2001 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket77?endpoint=http://localhost:57213®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/1/scratch/78a6254c5a3a7b70/build/TestClientCADerivations2686859678/001/store'2002 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120032026/10/25 13:22:48 INFO Received push request method=POST path=/api/pushes20042026/10/25 13:22:48 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/present2005--- PASS: TestCacheStatsHandler (6.35s)2006=== CONT TestClientErrorHandling/InvalidAuthToken20072026/10/25 13:22:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20082026/10/25 13:22:48 INFO Uploading 6km423z0q8564j39hzh7yb5c7kgv9f93-test-file-0.txt (160B)2009--- PASS: TestClientCADerivations (7.80s)2010=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20112026/10/25 13:22:48 INFO Uploading ab05xhb7if80w2waa1y1w42achlxxl2d-test-file-1.txt (160B)2012=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20132026/10/25 13:22:48 INFO Uploading vbqj3ds2izs1g4vbr565m2gqyj0is2id-test-file-2.txt (160B)20142026/10/25 13:22:48 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]2015=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2016=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20172026/10/25 13:22:48 WARN Authentication failed token_preview=eyJhbGciOi...UiWZHgGS3w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2018=== CONT TestService_RequireScope_OIDC/builder_may_write2019=== CONT TestService_RequireScope_OIDC/reader_may_read2020=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2021=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2022--- PASS: TestService_AuthMiddleware_OIDC (7.69s)2023 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2024 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2025 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2026 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20272026/10/25 13:22:48 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]2028=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc20292026/10/25 13:22:48 WARN Request failed, retrying attempt=2 backoff=219.386127ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2030=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc20312026/10/25 13:22:48 WARN Failed to register uploaded object key=6km423z0q8564j39hzh7yb5c7kgv9f93.ls error="server returned 404: 404 page not found\n"20322026/10/25 13:22:48 WARN Failed to register uploaded object key=ab05xhb7if80w2waa1y1w42achlxxl2d.ls error="server returned 404: 404 page not found\n"20332026/10/25 13:22:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"2034=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2035=== CONT TestService_RequireScope_OIDC/writer_implies_read2036=== CONT TestService_RequireScope_OIDC/ops_may_not_write20372026/10/25 13:22:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"2038=== CONT TestService_RequireScope_OIDC/static_token_may_write2039=== CONT TestService_RequireScope_OIDC/static_token_may_admin2040=== CONT TestService_RequireScope_OIDC/reader_may_not_write20412026/10/25 13:22:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"2042=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20432026/10/25 13:22:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2044=== CONT TestService_RequireScope_OIDC/ops_may_admin20452026/10/25 13:22:48 WARN Failed to register uploaded object key=vbqj3ds2izs1g4vbr565m2gqyj0is2id.ls error="server returned 404: 404 page not found\n"20462026/10/25 13:22:48 INFO Signed narinfos id=1 count=320472026/10/25 13:22:48 INFO Uploading 3 narinfos2048--- PASS: TestService_RequireScope_OIDC (7.36s)2049 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.02s)2053 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2061 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2062 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)20632026/10/25 13:22:49 WARN Failed to register uploaded object key=6km423z0q8564j39hzh7yb5c7kgv9f93.narinfo error="server returned 404: 404 page not found\n"20642026/10/25 13:22:49 WARN Failed to register uploaded object key=ab05xhb7if80w2waa1y1w42achlxxl2d.narinfo error="server returned 404: 404 page not found\n"20652026/10/25 13:22:49 INFO Received complete push request method=POST path=/api/pushes/1/complete20662026/10/25 13:22:49 WARN Failed to register uploaded object key=vbqj3ds2izs1g4vbr565m2gqyj0is2id.narinfo error="server returned 404: 404 page not found\n"20672026/10/25 13:22:49 INFO Completed push id=1 objects=9 duration=36.912042ms20682026/10/25 13:22:49 INFO Upload complete. (370ms)2069=== NAME TestClientMultipleUploads2070 client_integration_test.go:369: Uploaded 3 paths in 410.165542ms20712026/10/25 13:22:49 WARN Request failed, retrying attempt=3 backoff=424.495511ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2072--- PASS: TestClientMultipleUploads (8.25s)2073--- PASS: TestReadProxyConditionalGet (6.74s)20742026/10/25 13:22:49 WARN Request failed, retrying attempt=4 backoff=819.580348ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2075--- PASS: TestReadProxyRangeRequest (6.91s)2076=== NAME TestPinProtectsFromGC2077 client_integration_test.go:840: Pin successfully protected closure from garbage collection20782026-10-25 13:22:49.867 UTC [29713] LOG: checkpoint starting: wal2079--- PASS: TestPinProtectsFromGC (12.90s)20802026/10/25 13:22:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02081=== NAME TestClientIntegration2082 client_integration_test.go:323: Objects in database after GC:2083 client_integration_test.go:323: Successfully deleted all objects with GC --force2084--- PASS: TestClientIntegration (10.43s)2085--- PASS: TestReadRedirectKeepsNarinfoProxied (7.02s)20862026/10/25 13:22:50 WARN Request failed, retrying attempt=5 backoff=1.698064994s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2087--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.76s)2088--- PASS: TestReadRedirectNar (6.39s)2089--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.10s)20902026/10/25 13:22:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20912026/10/25 13:22:51 WARN mTLS auth: bound subjects configured but subject DN unavailable20922026/10/25 13:22:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2093--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.18s)2094--- PASS: TestService_ReadAuthMiddleware (5.99s)20952026/10/25 13:22:52 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-config20962026/10/25 13:22:52 INFO Received uploads request method=POST path=/api/pending_closures20972026/10/25 13:22:52 WARN Request failed, retrying attempt=2 backoff=182.739737ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20982026/10/25 13:22:52 INFO Received uploads request method=POST path=/api/pending_closures20992026/10/25 13:22:52 INFO Aborted multipart uploads count=0 kept=021002026/10/25 13:22:52 WARN Force mode enabled - objects will be deleted immediately without grace period21012026/10/25 13:22:52 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=021022026/10/25 13:22:52 INFO Vacuumed table table=pending_closures21032026/10/25 13:22:52 INFO Vacuumed table table=pending_objects21042026/10/25 13:22:52 INFO Vacuumed table table=multipart_uploads21052026/10/25 13:22:52 INFO Vacuumed table table=closures21062026/10/25 13:22:52 WARN Request failed, retrying attempt=3 backoff=409.29095ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21072026/10/25 13:22:52 INFO Vacuumed table table=objects21082026/10/25 13:22:52 INFO Received uploads request method=POST path=/api/pending_closures21092026/10/25 13:22:52 INFO Aborted multipart uploads count=0 kept=021102026/10/25 13:22:52 WARN Force mode enabled - objects will be deleted immediately without grace period21112026/10/25 13:22:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=02112--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2113 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.57s)2114 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.18s)21152026/10/25 13:22:52 INFO Vacuumed table table=pending_closures21162026/10/25 13:22:52 INFO Vacuumed table table=pending_objects21172026/10/25 13:22:52 INFO Vacuumed table table=multipart_uploads21182026/10/25 13:22:52 INFO Vacuumed table table=closures21192026/10/25 13:22:52 INFO Vacuumed table table=objects2120--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2121 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.68s)2122 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.76s)21232026/10/25 13:22:52 WARN Request failed, retrying attempt=4 backoff=747.341846ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21242026/10/25 13:22:53 INFO Aborted multipart uploads count=0 kept=021252026/10/25 13:22:53 WARN Force mode enabled - objects will be deleted immediately without grace period21262026/10/25 13:22:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:57213/bucket97/?delete=\": context canceled"2127--- PASS: TestPendingClosureWriteTimeout (0.04s)2128 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2129 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2130 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2131 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.43s)21322026/10/25 13:22:53 INFO Aborted multipart uploads count=0 kept=021332026/10/25 13:22:53 WARN Force mode enabled - objects will be deleted immediately without grace period21342026-10-25 13:22:53.191 UTC [30219] ERROR: canceling statement due to user request21352026-10-25 13:22:53.191 UTC [30219] STATEMENT: -- name: MarkStaleObjects :execrows2136 WITH RECURSIVE ct AS (2137 SELECT timezone('UTC', now()) AS now2138 ),2139 closure_reach AS (2140 -- Start with all closure keys2141 SELECT o.key, o.refs2142 FROM objects o2143 INNER JOIN closures c ON o.key = c.key2144 UNION2145 -- Recursively add all referenced objects2146 SELECT o.key, o.refs2147 FROM objects o2148 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2149 ),2150 reachable_objects AS (2151 SELECT DISTINCT key FROM closure_reach2152 ),2153 stale_objects AS (2154 SELECT o.key2155 FROM objects AS o, ct2156 WHERE2157 NOT EXISTS (2158 SELECT 12159 FROM reachable_objects ro2160 WHERE ro.key = o.key2161 )2162 AND NOT EXISTS (2163 SELECT 12164 FROM pending_objects AS po2165 WHERE po.key = o.key2166 )2167 AND o.deleted_at IS NULL -- Only mark fresh objects2168 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2169 FOR UPDATE2170 )2171 UPDATE objects2172 SET2173 deleted_at = ct.now,2174 first_deleted_at = COALESCE(first_deleted_at, ct.now)2175 FROM stale_objects, ct2176 WHERE objects.key = stale_objects.key2177 2178--- PASS: TestGCEndsOnShutdown (0.00s)2179 --- PASS: TestGCEndsOnShutdown/before_the_run (5.50s)2180 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.62s)2181 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.31s)21822026/10/25 13:22:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21832026/10/25 13:22:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21842026/10/25 13:22:53 WARN Request failed, retrying attempt=5 backoff=1.562285885s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/10/25 13:22:55 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"21862026/10/25 13:22:55 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-config21872026/10/25 13:22:55 WARN Request failed, retrying attempt=2 backoff=201.148018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2188--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.15s)21892026/10/25 13:22:55 WARN Request failed, retrying attempt=3 backoff=361.733306ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21902026/10/25 13:22:55 WARN Request failed, retrying attempt=4 backoff=736.863719ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21912026/10/25 13:22:56 WARN Request failed, retrying attempt=5 backoff=1.592172272s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/10/25 13:22:58 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_closures21932026/10/25 13:22:58 WARN Request failed, retrying attempt=2 backoff=205.011239ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21942026/10/25 13:22:58 WARN Request failed, retrying attempt=3 backoff=417.29664ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21952026/10/25 13:22:58 WARN Request failed, retrying attempt=4 backoff=853.30661ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21962026/10/25 13:22:59 WARN Request failed, retrying attempt=5 backoff=1.536036089s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2197--- PASS: TestClientErrorHandling (0.01s)2198 --- PASS: TestClientErrorHandling/InvalidStorePath (4.82s)2199 --- PASS: TestClientErrorHandling/InvalidAuthToken (4.64s)2200 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.88s)2201FAIL2202{"timestamp":"2026-10-25T13:23:01.371306Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57377","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}22032026-10-25 13:23:01.520 UTC [29708] LOG: received smart shutdown request22042026-10-25 13:23:01.521 UTC [29708] LOG: background worker "logical replication launcher" (PID 29718) exited with exit code 122052026-10-25 13:23:02.792 UTC [29713] LOG: checkpoint complete: wrote 11096 buffers (67.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.131 s, sync=0.666 s, total=12.925 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=533364 kB, estimate=533364 kB; lsn=0/22840F08, redo lsn=0/2206A30022062026-10-25 13:23:02.793 UTC [29713] LOG: shutting down22072026-10-25 13:23:02.793 UTC [29713] LOG: checkpoint starting: shutdown immediate22082026-10-25 13:23:02.861 UTC [29713] LOG: checkpoint complete: wrote 1081 buffers (6.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.031 s, sync=0.015 s, total=0.069 s; sync files=405, longest=0.001 s, average=0.001 s; distance=8027 kB, estimate=480831 kB; lsn=0/22840F80, redo lsn=0/22840F8022092026-10-25 13:23:02.877 UTC [29708] LOG: database system is shut down