niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #400
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestRetryTimeoutOutlastsMaxRetries56=== PAUSE TestRetryTimeoutOutlastsMaxRetries57=== RUN TestShellSplit58=== PAUSE TestShellSplit59=== RUN TestShellSplitErrors60=== PAUSE TestShellSplitErrors61=== RUN TestStreamPushReportsEveryPath62=== PAUSE TestStreamPushReportsEveryPath63=== RUN TestStreamPushBatchesUnderLoad64=== PAUSE TestStreamPushBatchesUnderLoad65=== RUN TestStreamPushIsolatesFailures66=== PAUSE TestStreamPushIsolatesFailures67=== RUN TestStreamPushGivesUpOnDeadServer68=== PAUSE TestStreamPushGivesUpOnDeadServer69=== RUN TestStreamPushRequestLine70=== PAUSE TestStreamPushRequestLine71=== RUN TestStreamPushReportsSignatures72=== PAUSE TestStreamPushReportsSignatures73=== RUN TestStreamPushReportsSkippedPaths74=== PAUSE TestStreamPushReportsSkippedPaths75=== RUN TestClientSignaturesByStorePath76=== PAUSE TestClientSignaturesByStorePath77=== RUN TestStreamPushStopsWhenCanceled78=== PAUSE TestStreamPushStopsWhenCanceled79=== RUN TestSetClientTLS80=== PAUSE TestSetClientTLS81=== RUN TestSetClientTLSDoesNotMutateDefaultTransport82=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport83=== RUN TestSetClientTLSErrors84=== PAUSE TestSetClientTLSErrors85=== RUN TestStaticToken86=== PAUSE TestStaticToken87=== RUN TestFileTokenReadsAndCaches88=== PAUSE TestFileTokenReadsAndCaches89=== RUN TestFileTokenMissing90=== PAUSE TestFileTokenMissing91=== RUN TestFileTokenEmpty92=== PAUSE TestFileTokenEmpty93=== RUN TestScriptTokenNoExpiryRerunsEveryCall94=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall95=== RUN TestScriptTokenCachesUntilRefresh96=== PAUSE TestScriptTokenCachesUntilRefresh97=== RUN TestScriptTokenEmptyToken98=== PAUSE TestScriptTokenEmptyToken99=== RUN TestScriptTokenBadJSON100=== PAUSE TestScriptTokenBadJSON101=== RUN TestScriptTokenScriptFails102=== PAUSE TestScriptTokenScriptFails103=== RUN TestScriptTokenEmptyCommand104=== PAUSE TestScriptTokenEmptyCommand105=== CONT TestDoServerRequestAttachesToken106=== CONT TestStreamPushGivesUpOnDeadServer107=== CONT TestFileTokenReadsAndCaches108=== CONT TestScriptTokenEmptyCommand109--- PASS: TestScriptTokenEmptyCommand (0.00s)110=== CONT TestParsePathInfoJSON111=== RUN TestParsePathInfoJSON/Nix_format112=== PAUSE TestParsePathInfoJSON/Nix_format113=== RUN TestParsePathInfoJSON/Lix_format114=== PAUSE TestParsePathInfoJSON/Lix_format115=== RUN TestParsePathInfoJSON/empty_input116=== PAUSE TestParsePathInfoJSON/empty_input117=== RUN TestParsePathInfoJSON/whitespace_only118=== PAUSE TestParsePathInfoJSON/whitespace_only119=== RUN TestParsePathInfoJSON/invalid_JSON120=== PAUSE TestParsePathInfoJSON/invalid_JSON121=== CONT TestPathInfoHashCompatibility122=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)123=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)124=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon125=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon126=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI127=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI128=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512129=== CONT TestScriptTokenScriptFails1302026/10/08 17:08:07 ERROR Upload failed error="connection refused" count=201312026/10/08 17:08:07 ERROR Server seems unavailable, giving up on batch untried=17132=== CONT TestScriptTokenBadJSON133--- PASS: TestFileTokenReadsAndCaches (0.00s)134=== CONT TestStreamPushStopsWhenCanceled135--- PASS: TestStreamPushStopsWhenCanceled (0.00s)136=== CONT TestStaticToken137--- PASS: TestStaticToken (0.00s)138=== CONT TestSetClientTLSErrors139=== CONT TestScriptTokenEmptyToken140=== CONT TestScriptTokenCachesUntilRefresh141=== CONT TestScriptTokenNoExpiryRerunsEveryCall142=== CONT TestFileTokenEmpty143=== CONT TestFileTokenMissing144=== CONT TestGetStorePathHash145=== RUN TestGetStorePathHash/valid_store_path146=== CONT TestStreamPushIsolatesFailures147=== PAUSE TestGetStorePathHash/valid_store_path148=== RUN TestGetStorePathHash/basename_without_hyphen_should_error149=== CONT TestStreamPushBatchesUnderLoad150=== CONT TestStreamPushReportsEveryPath151=== CONT TestShellSplitErrors152=== CONT TestShellSplit153=== CONT TestRetryTimeoutOutlastsMaxRetries154=== CONT TestDoWithRetry_BodyReplayedViaGetBody155=== CONT TestResolveStorePath156=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess157=== CONT TestRateLimiterFeedback158=== CONT TestPathInfoCACompatibility159=== CONT TestParsePathInfoJSONMultiplePaths160=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512161--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)162=== CONT TestSetClientTLSDoesNotMutateDefaultTransport163=== CONT TestSetClientTLS164=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1652026/10/08 17:08:07 ERROR Upload failed error="bad path" count=3166=== CONT TestClientSignaturesByStorePath167=== CONT TestUploadMultipart_SupersededByPeer168=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error169=== RUN TestRateLimiterFeedback/429_enables_limiter1702026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5171=== RUN TestSetClientTLSErrors/missing_cert_file172=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths173=== CONT TestStreamPushReportsSkippedPaths174--- PASS: TestShellSplit (0.00s)175=== CONT TestEncodeNixBase32WithRealHash176=== CONT TestConvertHashToNix32177=== PAUSE TestRateLimiterFeedback/429_enables_limiter178=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error179--- PASS: TestShellSplitErrors (0.00s)180--- PASS: TestStreamPushIsolatesFailures (0.00s)181--- PASS: TestClientSignaturesByStorePath (0.00s)182--- PASS: TestFileTokenEmpty (0.00s)183=== CONT TestEncodeNixBase32184=== CONT TestDumpPathSingleFile185=== CONT TestDumpPathMatchesNix186=== RUN TestUploadMultipart_SupersededByPeer/exists187=== PAUSE TestUploadMultipart_SupersededByPeer/exists188=== PAUSE TestSetClientTLSErrors/missing_cert_file189=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error190=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error191=== RUN TestConvertHashToNix32/SRI_format_to_Nix32192=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32193=== CONT TestStreamPushReportsSignatures194=== CONT TestCaseHackSuffix195=== RUN TestEncodeNixBase32/test_string_hash196=== RUN TestPathInfoCACompatibility/null_ca_field197=== PAUSE TestPathInfoCACompatibility/null_ca_field198=== CONT TestDumpPathWriterError199=== RUN TestPathInfoCACompatibility/old_string_format_-_text200=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201--- PASS: TestFileTokenMissing (0.00s)202--- PASS: TestScriptTokenScriptFails (0.01s)203--- PASS: TestEncodeNixBase32WithRealHash (0.00s)204--- PASS: TestStreamPushReportsSkippedPaths (0.00s)205--- PASS: TestStreamPushReportsEveryPath (0.00s)206=== PAUSE TestEncodeNixBase32/test_string_hash207--- PASS: TestDoServerRequestAttachesToken (0.01s)208--- PASS: TestResolveStorePath (0.00s)209=== CONT TestUploadMultipart_PartsInParallel2102026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:54691211=== RUN TestRateLimiterFeedback/503_enables_limiter212=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text213=== CONT TestFilterOversizedClosures214=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive215=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive216=== RUN TestPathInfoCACompatibility/new_structured_format_-_text217=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text218=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method219=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method220=== RUN TestConvertHashToNix32/already_Nix32_format221=== PAUSE TestConvertHashToNix32/already_Nix32_format222=== RUN TestConvertHashToNix32/invalid_format223=== PAUSE TestConvertHashToNix32/invalid_format224=== RUN TestEncodeNixBase32/empty_input225=== PAUSE TestEncodeNixBase32/empty_input226=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica227=== RUN TestSetClientTLS/rejects_connection_without_client_cert228=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert229=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA230=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA231=== RUN TestSetClientTLS/preserves_debug_logging_transport232=== PAUSE TestSetClientTLS/preserves_debug_logging_transport233=== RUN TestFilterOversizedClosures/no_limit_keeps_everything234=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything235=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped236=== RUN TestUploadMultipart_SupersededByPeer/missing237=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238=== RUN TestSetClientTLSErrors/missing_key_file239--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)2402026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5241=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths242=== PAUSE TestRateLimiterFeedback/503_enables_limiter243=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun244=== CONT TestRegisterUploadedObjectReusesConnections245=== CONT TestStreamPushRequestLine246=== CONT TestPartSizeForNAR247=== PAUSE TestUploadMultipart_SupersededByPeer/missing248=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter249=== PAUSE TestSetClientTLSErrors/missing_key_file2502026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:54693251=== RUN TestPartSizeForNAR/zero_stays_at_minimum252=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2532026/10/08 17:08:07 ERROR Upload failed error=boom count=1254=== RUN TestPartSizeForNAR/small_stays_at_minimum255=== RUN TestFilterOversizedClosures/all_closures_skipped256--- PASS: TestStreamPushReportsSignatures (0.00s)257=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths258=== CONT TestParsePathInfoJSON/Nix_format259=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter260=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter261=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2622026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=52632026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:546932642026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:54691265=== CONT TestParsePathInfoJSON/invalid_JSON266=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512267=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2682026/10/08 17:08:07 ERROR Upload failed error=boom count=1269=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon270=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)271--- PASS: TestPathInfoHashCompatibility (0.00s)272 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)273 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)274 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)275 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)276=== CONT TestGetStorePathHash/valid_store_path277=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error278=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error279=== CONT TestPathInfoCACompatibility/null_ca_field280=== CONT TestParsePathInfoJSON/Lix_format2812026/10/08 17:08:07 INFO Garbage collection started282=== CONT TestEncodeNixBase32/test_string_hash283=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== CONT TestPathInfoCACompatibility/new_structured_format_-_text285=== CONT TestParsePathInfoJSON/whitespace_only286=== CONT TestPathInfoCACompatibility/old_string_format_-_text2872026/10/08 17:08:07 INFO Garbage collection started288=== PAUSE TestPartSizeForNAR/small_stays_at_minimum289=== PAUSE TestFilterOversizedClosures/all_closures_skipped290=== RUN TestSetClientTLSErrors/missing_ca_file291=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum292=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum293=== CONT TestParsePathInfoJSON/empty_input294=== CONT TestEncodeNixBase32/empty_input295=== CONT TestSetClientTLS/rejects_connection_without_client_cert296=== PAUSE TestSetClientTLSErrors/missing_ca_file297=== RUN TestSetClientTLSErrors/invalid_ca_file298=== PAUSE TestSetClientTLSErrors/invalid_ca_file299--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)300=== CONT TestSetClientTLS/preserves_debug_logging_transport301=== CONT TestGetStorePathHash/basename_without_hyphen_should_error302=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive303=== CONT TestUploadMultipart_SupersededByPeer/exists304=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA305=== CONT TestConvertHashToNix32/SRI_format_to_Nix32306=== CONT TestUploadMultipart_SupersededByPeer/missing307=== CONT TestConvertHashToNix32/invalid_format308=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths309=== CONT TestConvertHashToNix32/already_Nix32_format310=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts311=== CONT TestRateLimiterFeedback/429_enables_limiter312=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts313=== RUN TestPartSizeForNAR/1_TiB314=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths315=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter316--- PASS: TestGetStorePathHash (0.00s)317 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)318 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)319 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)320 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)321=== PAUSE TestPartSizeForNAR/1_TiB322=== RUN TestPartSizeForNAR/5_TiB_S3_max_object323=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object324=== RUN TestPartSizeForNAR/capped_at_5_GiB325=== PAUSE TestPartSizeForNAR/capped_at_5_GiB326=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter327--- PASS: TestPathInfoCACompatibility (0.00s)328 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)329 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)330 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)331 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)332 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)333--- PASS: TestEncodeNixBase32 (0.00s)334 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)335 --- PASS: TestEncodeNixBase32/empty_input (0.00s)336--- PASS: TestParsePathInfoJSON (0.00s)337 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)338 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)339 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)341 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)342--- PASS: TestConvertHashToNix32 (0.00s)343 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)344 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)345 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)346--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)347 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3492026/10/08 17:08: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=03502026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:54691351--- PASS: TestScriptTokenBadJSON (0.02s)352=== CONT TestRateLimiterFeedback/503_enables_limiter353--- PASS: TestScriptTokenEmptyToken (0.02s)354=== CONT TestFilterOversizedClosures/no_limit_keeps_everything355=== CONT TestFilterOversizedClosures/all_closures_skipped3562026/10/08 17:08: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=50357=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3582026/10/08 17:08: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=2000359--- PASS: TestFilterOversizedClosures (0.01s)360 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)361 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)362 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)363=== CONT TestSetClientTLSErrors/missing_cert_file364=== CONT TestSetClientTLSErrors/missing_key_file365=== CONT TestSetClientTLSErrors/invalid_ca_file366=== CONT TestSetClientTLSErrors/missing_ca_file367=== CONT TestPartSizeForNAR/zero_stays_at_minimum368=== CONT TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestPartSizeForNAR/5_TiB_S3_max_object370=== CONT TestPartSizeForNAR/1_TiB371=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts372=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum373=== CONT TestPartSizeForNAR/small_stays_at_minimum374--- PASS: TestPartSizeForNAR (0.01s)375 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)377 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)378 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)379 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)3832026/10/08 17:08:07 WARN Garbage collection finished on another replica. Its statistics are not available here3842026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=53852026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:54766386--- PASS: TestSetClientTLSErrors (0.02s)387 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)3922026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:546913932026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:54691394--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)395 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)396 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)3972026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:546913982026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=53992026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=54002026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:547624012026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:546914022026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=5403--- PASS: TestRateLimiterFeedback (0.01s)404 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)405 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)406 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)407 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)408--- PASS: TestStreamPushRequestLine (0.02s)4092026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:546914102026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:546914112026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:546914122026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:546914132026/10/08 17:08:07 http: TLS handshake error from 127.0.0.1:54745: read tcp 127.0.0.1:54697->127.0.0.1:54745: use of closed network connection414--- PASS: TestSetClientTLS (0.01s)415 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)416 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)417 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4182026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:546914192026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:546914202026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:54691421--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)4222026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:546914232026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:54691424--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)4252026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:546914262026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:54691427--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)4282026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:54691429--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)430--- PASS: TestDumpPathSingleFile (0.06s)431--- PASS: TestDumpPathWriterError (0.06s)432--- PASS: TestCaseHackSuffix (0.07s)433--- PASS: TestDumpPathMatchesNix (0.09s)434--- PASS: TestStreamPushBatchesUnderLoad (0.10s)435--- PASS: TestUploadMultipart_PartsInParallel (0.62s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "_tribuchetbld3".440This user must also own the server process.441442The database cluster will be initialized with locale "C".443The default database encoding has accordingly been set to "SQL_ASCII".444The default text search configuration will be set to "english".445446Data page checksums are enabled.447448creating directory /private/var/tb/3/scratch/7db02954dc0d9130/build/postgres3277253486/data ... ok449creating subdirectories ... ok450selecting dynamic shared memory implementation ... posix451selecting default "max_connections" ... 100452selecting default "shared_buffers" ... 128MB453selecting default time zone ... UTC454creating configuration files ... ok455running bootstrap script ... ok456performing post-bootstrap initialization ... ok457syncing data to disk ... ok458459initdb: warning: enabling "trust" authentication for local connections460initdb: 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.461462Success. You can now start the database server using:463464 pg_ctl -D /private/var/tb/3/scratch/7db02954dc0d9130/build/postgres3277253486/data -l logfile start465466/private/var/tb/3/scratch/7db02954dc0d9130/build/postgres3277253486:5432 - no response4672026-10-08 17:08:09.542 UTC [74678] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4682026-10-08 17:08:09.542 UTC [74678] LOG: listening on Unix socket "/private/var/tb/3/scratch/7db02954dc0d9130/build/postgres3277253486/.s.PGSQL.5432"4692026-10-08 17:08:09.544 UTC [74685] LOG: database system was shut down at 2026-10-08 17:08:09 UTC4702026-10-08 17:08:09.545 UTC [74678] LOG: database system is ready to accept connections471/private/var/tb/3/scratch/7db02954dc0d9130/build/postgres3277253486:5432 - accepting connections472{"timestamp":"2026-10-08T17:08:09.760142Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"86a6f018-510e-4ded-8e2d-d3fe03201502","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)"}473=== RUN TestService_AuthMiddleware474=== PAUSE TestService_AuthMiddleware475=== RUN TestService_AuthMiddleware_MTLSProxyHeader476=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader477=== RUN TestService_AuthMiddleware_MTLSBoundSubjects478=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects479=== RUN TestService_ReadAuthMiddleware480=== PAUSE TestService_ReadAuthMiddleware481=== RUN TestService_AuthMiddleware_OIDC482=== PAUSE TestService_AuthMiddleware_OIDC483=== RUN TestService_RequireScope_OIDC484=== PAUSE TestService_RequireScope_OIDC485=== RUN TestService_ReadScope_PublicByDefault486=== PAUSE TestService_ReadScope_PublicByDefault487=== RUN TestCacheConfigHandler488=== PAUSE TestCacheConfigHandler489=== RUN TestCacheStatsHandler490=== PAUSE TestCacheStatsHandler491=== RUN TestClientCADerivations492=== PAUSE TestClientCADerivations493=== RUN TestClientErrorHandling494=== PAUSE TestClientErrorHandling495=== RUN TestClientIntegration496=== PAUSE TestClientIntegration497=== RUN TestClientMultipleUploads498=== PAUSE TestClientMultipleUploads499=== RUN TestClientWithDependencies500=== PAUSE TestClientWithDependencies501=== RUN TestClientSharedPathCommittedMidPush502=== PAUSE TestClientSharedPathCommittedMidPush503=== RUN TestPinProtectsFromGC504=== PAUSE TestPinProtectsFromGC505=== RUN TestClientPushesUseOnePush506=== PAUSE TestClientPushesUseOnePush507=== RUN TestClientFallsBackToClosures508=== PAUSE TestClientFallsBackToClosures509=== RUN TestDeleteClosuresRacingPins510=== PAUSE TestDeleteClosuresRacingPins511=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock512=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock513=== RUN TestResolveDBConnectionString514=== PAUSE TestResolveDBConnectionString515=== RUN TestConnectWaitsForAPeerMigration516=== PAUSE TestConnectWaitsForAPeerMigration517=== RUN TestLeadElectsOneAndHandsOver518=== PAUSE TestLeadElectsOneAndHandsOver519=== RUN TestLeadIncumbentWinsAfterRestart5202026/10/08 17:08:10 INFO lead: acquired remote=192.0.2.1:12345212026/10/08 17:08:10 INFO lead: released remote=192.0.2.1:12345222026/10/08 17:08:10 INFO lead: acquired remote=192.0.2.1:12345232026/10/08 17:08:11 INFO lead: released remote=192.0.2.1:1234524--- PASS: TestLeadIncumbentWinsAfterRestart (1.96s)525=== RUN TestLeadIncumbentAnnouncesAtOnce526=== PAUSE TestLeadIncumbentAnnouncesAtOnce527=== RUN TestLeadEndsOnShutdown528=== PAUSE TestLeadEndsOnShutdown529=== RUN TestLeadEndsWhenItsConnectionHangs5302026/10/08 17:08:12 INFO lead: acquired remote=192.0.2.1:12345312026-10-08 17:08:13.429 UTC [74723] FATAL: terminating connection due to administrator command5322026/10/08 17:08:13 INFO lead: acquired remote=192.0.2.1:12345332026/10/08 17:08:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5342026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:12345352026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:1234536--- PASS: TestLeadEndsWhenItsConnectionHangs (3.00s)537=== RUN TestGCAdvisoryLockBlocksConcurrentRun538=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun539=== RUN TestGCBugBareHashReferences540=== PAUSE TestGCBugBareHashReferences541=== RUN TestGCMetrics542=== PAUSE TestGCMetrics543=== RUN TestPushDedupSurvivesConcurrentGC544=== PAUSE TestPushDedupSurvivesConcurrentGC545=== RUN TestDeduplicatedObjectsRecordedAsPending546=== PAUSE TestDeduplicatedObjectsRecordedAsPending547=== RUN TestGCSweepSkipsPendingObjects548=== PAUSE TestGCSweepSkipsPendingObjects549=== RUN TestTombstonedObjectOfferedWithoutWaiting550=== PAUSE TestTombstonedObjectOfferedWithoutWaiting551=== RUN TestGCSweepDeliversEachKeyOnce552=== PAUSE TestGCSweepDeliversEachKeyOnce553=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection554=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection555=== RUN TestForceGCDuringPushOffersSweptObject556=== PAUSE TestForceGCDuringPushOffersSweptObject557=== RUN TestFailedS3DeleteKeepsTombstone558=== PAUSE TestFailedS3DeleteKeepsTombstone559=== RUN TestSweepSkipsRowsLockedByPush560=== PAUSE TestSweepSkipsRowsLockedByPush561=== RUN TestRegisterCompletedObjectNeedsPendingRow562=== PAUSE TestRegisterCompletedObjectNeedsPendingRow563=== RUN TestGetExistingObjectsLocksRows564=== PAUSE TestGetExistingObjectsLocksRows565=== RUN TestSweepRechecksPendingAfterLocking566=== PAUSE TestSweepRechecksPendingAfterLocking567=== RUN TestPushWaitsForSweepHoldingRow568=== PAUSE TestPushWaitsForSweepHoldingRow569=== RUN TestCommitRacingPendingCleanupKeepsObjects570=== PAUSE TestCommitRacingPendingCleanupKeepsObjects571=== RUN TestGCEndsOnShutdown572=== PAUSE TestGCEndsOnShutdown573=== RUN TestGCTaskStore_StartNew574=== PAUSE TestGCTaskStore_StartNew575=== RUN TestGCTaskStore_DeduplicateSameParams576=== PAUSE TestGCTaskStore_DeduplicateSameParams577=== RUN TestGCTaskStore_ConflictDifferentParams578=== PAUSE TestGCTaskStore_ConflictDifferentParams579=== RUN TestGCTaskStore_GetEmpty580=== PAUSE TestGCTaskStore_GetEmpty581=== RUN TestGCTaskStore_GetReturnsLatest582=== PAUSE TestGCTaskStore_GetReturnsLatest583=== RUN TestGCTaskStore_CompletedAllowsNewTask584=== PAUSE TestGCTaskStore_CompletedAllowsNewTask585=== RUN TestGCTaskStore_PhaseUpdates586=== PAUSE TestGCTaskStore_PhaseUpdates587=== RUN TestGCTaskStore_Fail588=== PAUSE TestGCTaskStore_Fail589=== RUN TestGracefulShutdownDrainsInflight590=== PAUSE TestGracefulShutdownDrainsInflight591=== RUN TestService_healthCheckHandler592=== PAUSE TestService_healthCheckHandler593=== RUN TestService_readinessHandler594=== PAUSE TestService_readinessHandler595=== RUN TestGenerateLandingPage596=== PAUSE TestGenerateLandingPage597=== RUN TestCacheConfigHandlerMaxNarSize598=== PAUSE TestCacheConfigHandlerMaxNarSize599=== RUN TestCreatePendingClosureRejectsOversizedNAR600=== PAUSE TestCreatePendingClosureRejectsOversizedNAR601=== RUN TestNARDeduplicationMetadataUploadBug602=== PAUSE TestNARDeduplicationMetadataUploadBug603=== RUN TestMetricsInventory604=== PAUSE TestMetricsInventory605=== RUN TestMetricsCommit606=== PAUSE TestMetricsCommit607=== RUN TestService_NativeMTLS608=== PAUSE TestService_NativeMTLS609=== RUN TestServerTLSConfig610=== PAUSE TestServerTLSConfig611=== RUN TestMultipartCleanup612=== PAUSE TestMultipartCleanup613=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded614=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded615=== RUN TestPendingCleanupUsesOneCutoff616=== PAUSE TestPendingCleanupUsesOneCutoff617=== RUN TestObjectStatsTrigger618=== PAUSE TestObjectStatsTrigger619=== RUN TestObjectStatsLargeCommit620=== PAUSE TestObjectStatsLargeCommit621=== RUN TestOrphanedObjectsGC622=== PAUSE TestOrphanedObjectsGC623=== RUN TestOrphanedObjectsGCStressTest624=== PAUSE TestOrphanedObjectsGCStressTest625=== RUN TestCreatePin_ReservedPins626=== PAUSE TestCreatePin_ReservedPins627=== RUN TestPresentReportsOnlyClosureRoots628=== PAUSE TestPresentReportsOnlyClosureRoots629=== RUN TestPresentRefreshesOnlyStaleClosures630=== PAUSE TestPresentRefreshesOnlyStaleClosures631=== RUN TestPresentNotReportedWhileGCDeletesClosure632=== PAUSE TestPresentNotReportedWhileGCDeletesClosure633=== RUN TestParseSingleRange634=== PAUSE TestParseSingleRange635=== RUN TestProxyHeadersOnlyTrustedOnSocket6362026/10/08 17:08:15 INFO Starting HTTP server address=127.0.0.1:548086372026/10/08 17:08:15 INFO Starting HTTP server address=proxy.sock6382026/10/08 17:08:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6392026/10/08 17:08:15 INFO Shutdown signal received, draining in-flight requests timeout=10s640--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.21s)641=== RUN TestIsValidCachePath642=== PAUSE TestIsValidCachePath643=== RUN TestReadProxyNarinfo644=== PAUSE TestReadProxyNarinfo645=== RUN TestReadProxyNarinfoAlreadyDecompressed646=== PAUSE TestReadProxyNarinfoAlreadyDecompressed647=== RUN TestReadProxyContentNegotiation648=== PAUSE TestReadProxyContentNegotiation649=== RUN TestReadProxyNarStreaming650=== PAUSE TestReadProxyNarStreaming651=== RUN TestReadProxy404652=== PAUSE TestReadProxy404653=== RUN TestReadProxyInvalidPath654=== PAUSE TestReadProxyInvalidPath655=== RUN TestReadProxyHead656=== PAUSE TestReadProxyHead657=== RUN TestReadProxyOutlastsServerWriteTimeout658=== PAUSE TestReadProxyOutlastsServerWriteTimeout659=== RUN TestReadProxyConditionalGet660=== PAUSE TestReadProxyConditionalGet661=== RUN TestReadProxyRootRedirectsToIndexHTML662=== PAUSE TestReadProxyRootRedirectsToIndexHTML663=== RUN TestReadProxyDisabled664=== PAUSE TestReadProxyDisabled665=== RUN TestReadRedirectNar666=== PAUSE TestReadRedirectNar667=== RUN TestReadRedirectKeepsNarinfoProxied668=== PAUSE TestReadRedirectKeepsNarinfoProxied669=== RUN TestReadProxyRangeRequest670=== PAUSE TestReadProxyRangeRequest671=== RUN TestReadRedirectUsesPublicS3URL672=== PAUSE TestReadRedirectUsesPublicS3URL673=== RUN TestPush_OverlappingRootsStoreOneRowPerKey674=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey675=== RUN TestPush_CompleteCommitsEveryRoot676=== PAUSE TestPush_CompleteCommitsEveryRoot677=== RUN TestPush_RepeatedRootCommitsOnce678=== PAUSE TestPush_RepeatedRootCommitsOnce679=== RUN TestPush_CompleteWaitsForCleanupOfThePush680=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush681=== RUN TestPush_RootsAreLockedInByteOrder682=== PAUSE TestPush_RootsAreLockedInByteOrder683=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit684=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit685=== RUN TestPush_RejectsBadRequests686=== PAUSE TestPush_RejectsBadRequests687=== RUN TestPush_SignsNarinfosOfItsPendingObjects688=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects689=== RUN TestRedundantMultipartUpload690=== PAUSE TestRedundantMultipartUpload691=== RUN TestCompleteMultipartUpload_ErrorButObjectExists692=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists693=== RUN TestCompletedNarNotReofferedAcrossClosures694=== PAUSE TestCompletedNarNotReofferedAcrossClosures695=== RUN TestPresignedUploadRegisteredBeforeCommit696=== PAUSE TestPresignedUploadRegisteredBeforeCommit697=== RUN TestService_Rustfstest698=== PAUSE TestService_Rustfstest699=== RUN TestParseSize700=== PAUSE TestParseSize701=== RUN TestSkippedUploadsHandler702=== PAUSE TestSkippedUploadsHandler703=== RUN TestSystemdListenerNotActivated704--- PASS: TestSystemdListenerNotActivated (0.00s)705=== RUN TestWatchdogBeatsWhenHealthy706--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)707=== RUN TestWatchdogSkipsWhenUnhealthy7082026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7172026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"718--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)719=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle720=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle721=== RUN TestProxyWriteTimeout722=== PAUSE TestProxyWriteTimeout723=== RUN TestPendingClosureWriteTimeout724=== PAUSE TestPendingClosureWriteTimeout725=== RUN TestIsValidUploadKey726=== PAUSE TestIsValidUploadKey727=== RUN TestUploadHandlersRejectInvalidKeys728=== PAUSE TestUploadHandlersRejectInvalidKeys729=== RUN TestUploadHandlersRejectOversizedBody730=== PAUSE TestUploadHandlersRejectOversizedBody731=== RUN TestService_cleanupPendingClosuresHandler732=== PAUSE TestService_cleanupPendingClosuresHandler733=== RUN TestService_createPendingClosureHandler734=== PAUSE TestService_createPendingClosureHandler735=== RUN TestService_verifyS3Integrity736=== PAUSE TestService_verifyS3Integrity737=== RUN TestCompleteMultipartUnregistered738=== PAUSE TestCompleteMultipartUnregistered739=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT740=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT741=== CONT TestCompletedNarNotReofferedAcrossClosures742=== CONT TestNARDeduplicationMetadataUploadBug743=== CONT TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh745=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh746=== CONT TestPush_SignsNarinfosOfItsPendingObjects747=== CONT TestMetricsInventory748=== CONT TestReadProxyNarStreaming749=== CONT TestReadProxyContentNegotiation750=== CONT TestReadProxyNarinfoAlreadyDecompressed751=== CONT TestReadProxyNarinfo752=== CONT TestReadProxy404753=== CONT TestIsValidCachePath754=== RUN TestIsValidCachePath/narinfo755=== CONT TestCompleteMultipartUpload_ErrorButObjectExists756=== CONT TestParseSingleRange757=== CONT TestRedundantMultipartUpload758=== RUN TestParseSingleRange/none759=== CONT TestPush_RejectsBadRequests760=== PAUSE TestParseSingleRange/none761=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit762=== CONT TestPush_RootsAreLockedInByteOrder763=== CONT TestPush_CompleteWaitsForCleanupOfThePush764=== CONT TestPush_RepeatedRootCommitsOnce765=== CONT TestPush_CompleteCommitsEveryRoot766=== CONT TestPush_OverlappingRootsStoreOneRowPerKey767=== CONT TestReadRedirectUsesPublicS3URL768=== CONT TestReadProxyRangeRequest769=== CONT TestService_AuthMiddleware770=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale771=== PAUSE TestIsValidCachePath/narinfo772=== RUN TestParseSingleRange/unknown_unit773=== PAUSE TestParseSingleRange/unknown_unit774=== RUN TestParseSingleRange/multi-range_ignored775=== PAUSE TestParseSingleRange/multi-range_ignored776=== RUN TestParseSingleRange/malformed_no_dash777=== PAUSE TestParseSingleRange/malformed_no_dash778=== RUN TestParseSingleRange/malformed_both_empty779=== PAUSE TestParseSingleRange/malformed_both_empty780=== RUN TestParseSingleRange/malformed_end_before_start781=== PAUSE TestParseSingleRange/malformed_end_before_start782=== RUN TestParseSingleRange/closed783=== PAUSE TestParseSingleRange/closed784=== RUN TestParseSingleRange/open-ended785=== PAUSE TestParseSingleRange/open-ended786=== RUN TestParseSingleRange/end_clamped_to_size787=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale788=== CONT TestReadRedirectKeepsNarinfoProxied789=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars790=== PAUSE TestParseSingleRange/end_clamped_to_size791=== RUN TestParseSingleRange/suffix792=== PAUSE TestParseSingleRange/suffix793=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars794=== RUN TestParseSingleRange/suffix_exceeds_size795=== PAUSE TestParseSingleRange/suffix_exceeds_size796=== RUN TestIsValidCachePath/nar_zst797=== RUN TestParseSingleRange/single_byte798=== PAUSE TestIsValidCachePath/nar_zst799=== PAUSE TestParseSingleRange/single_byte800=== RUN TestIsValidCachePath/nar_xz801=== PAUSE TestIsValidCachePath/nar_xz802=== RUN TestIsValidCachePath/nar_bz2803=== RUN TestParseSingleRange/start_past_EOF804=== PAUSE TestIsValidCachePath/nar_bz2805=== PAUSE TestParseSingleRange/start_past_EOF806=== RUN TestParseSingleRange/start_far_past_EOF807=== RUN TestIsValidCachePath/nar_uncompressed808=== PAUSE TestParseSingleRange/start_far_past_EOF809=== PAUSE TestIsValidCachePath/nar_uncompressed810=== RUN TestIsValidCachePath/ls811=== CONT TestReadRedirectNar812=== PAUSE TestIsValidCachePath/ls813=== RUN TestIsValidCachePath/log814=== PAUSE TestIsValidCachePath/log815=== RUN TestIsValidCachePath/realisation816=== PAUSE TestIsValidCachePath/realisation817=== RUN TestIsValidCachePath/nix-cache-info818=== PAUSE TestIsValidCachePath/nix-cache-info819=== RUN TestIsValidCachePath/index.html820=== PAUSE TestIsValidCachePath/index.html821=== RUN TestIsValidCachePath/traversal_parent822=== PAUSE TestIsValidCachePath/traversal_parent823=== RUN TestIsValidCachePath/traversal_in_middle824=== PAUSE TestIsValidCachePath/traversal_in_middle825=== RUN TestIsValidCachePath/invalid_char_e826=== PAUSE TestIsValidCachePath/invalid_char_e827=== RUN TestIsValidCachePath/invalid_char_u828=== PAUSE TestIsValidCachePath/invalid_char_u829=== RUN TestIsValidCachePath/random_path830=== PAUSE TestIsValidCachePath/random_path831=== RUN TestIsValidCachePath/empty832=== PAUSE TestIsValidCachePath/empty833=== RUN TestIsValidCachePath/leading_slash834=== PAUSE TestIsValidCachePath/leading_slash835=== RUN TestIsValidCachePath/wrong_extension836=== PAUSE TestIsValidCachePath/wrong_extension837=== RUN TestIsValidCachePath/short_hash838=== PAUSE TestIsValidCachePath/short_hash839=== CONT TestReadProxyDisabled8402026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes8412026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8422026/10/08 17:08:16 INFO Signed narinfos id=1 count=18432026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8442026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8452026/10/08 17:08:16 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8462026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8472026/10/08 17:08:16 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8482026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8492026/10/08 17:08:16 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18502026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8512026/10/08 17:08:16 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo852--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.29s)853=== CONT TestReadProxyRootRedirectsToIndexHTML854--- PASS: TestReadProxyRangeRequest (1.50s)855=== CONT TestReadProxyConditionalGet856--- PASS: TestReadProxy404 (2.03s)857=== CONT TestReadProxyOutlastsServerWriteTimeout8582026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures8592026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8602026/10/08 17:08:17 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLmQzYTllNGYyLTgxOTktNDJhOS1iM2I2LWQ3YTA1Y2U0ZjQyY3gxNzkxNDc5Mjk3NTA3MzQ1MDAw861--- PASS: TestMetricsInventory (2.55s)862=== CONT TestReadProxyHead8632026/10/08 17:08:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLmQzYTllNGYyLTgxOTktNDJhOS1iM2I2LWQ3YTA1Y2U0ZjQyY3gxNzkxNDc5Mjk3NTA3MzQ1MDAw parts=1864--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.55s)865=== CONT TestIsValidUploadKey866=== RUN TestIsValidUploadKey/narinfo867=== PAUSE TestIsValidUploadKey/narinfo868=== RUN TestIsValidUploadKey/nar_zst869=== PAUSE TestIsValidUploadKey/nar_zst870=== RUN TestIsValidUploadKey/nar_xz871=== PAUSE TestIsValidUploadKey/nar_xz872=== RUN TestIsValidUploadKey/nar_plain873=== PAUSE TestIsValidUploadKey/nar_plain874=== RUN TestIsValidUploadKey/listing875=== PAUSE TestIsValidUploadKey/listing876=== RUN TestIsValidUploadKey/build_log877=== PAUSE TestIsValidUploadKey/build_log878=== RUN TestIsValidUploadKey/build_log_home-manager_file879=== PAUSE TestIsValidUploadKey/build_log_home-manager_file880=== RUN TestIsValidUploadKey/build_log_plus_in_name881=== PAUSE TestIsValidUploadKey/build_log_plus_in_name882=== RUN TestIsValidUploadKey/build_log_question_mark883=== PAUSE TestIsValidUploadKey/build_log_question_mark884=== RUN TestIsValidUploadKey/build_log_equals885=== PAUSE TestIsValidUploadKey/build_log_equals886=== RUN TestIsValidUploadKey/realisation887=== PAUSE TestIsValidUploadKey/realisation888=== RUN TestIsValidUploadKey/realisation_plus_in_output889=== PAUSE TestIsValidUploadKey/realisation_plus_in_output890=== RUN TestIsValidUploadKey/nix-cache-info891=== PAUSE TestIsValidUploadKey/nix-cache-info892=== RUN TestIsValidUploadKey/index.html893=== PAUSE TestIsValidUploadKey/index.html894=== RUN TestIsValidUploadKey/narinfo_key,_nar_type895=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type896=== RUN TestIsValidUploadKey/nar_key,_narinfo_type897=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type898=== RUN TestIsValidUploadKey/listing_key,_narinfo_type899=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type900=== RUN TestIsValidUploadKey/traversal901=== PAUSE TestIsValidUploadKey/traversal902=== RUN TestIsValidUploadKey/traversal_nar903=== PAUSE TestIsValidUploadKey/traversal_nar904=== RUN TestIsValidUploadKey/absolute905=== PAUSE TestIsValidUploadKey/absolute906=== RUN TestIsValidUploadKey/empty_key907=== PAUSE TestIsValidUploadKey/empty_key908=== RUN TestIsValidUploadKey/unknown_type909=== PAUSE TestIsValidUploadKey/unknown_type910=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT911--- PASS: TestReadProxyNarStreaming (2.71s)912=== CONT TestCompleteMultipartUnregistered9132026/10/08 17:08:18 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"914--- PASS: TestService_AuthMiddleware (2.86s)915=== CONT TestService_verifyS3Integrity916--- PASS: TestReadProxyContentNegotiation (3.18s)917=== CONT TestService_createPendingClosureHandler918=== RUN TestPush_RejectsBadRequests/no_objects919=== PAUSE TestPush_RejectsBadRequests/no_objects920=== RUN TestPush_RejectsBadRequests/bad_root921=== PAUSE TestPush_RejectsBadRequests/bad_root922=== RUN TestPush_RejectsBadRequests/root_not_in_objects923=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects924=== RUN TestPush_RejectsBadRequests/no_roots925=== PAUSE TestPush_RejectsBadRequests/no_roots926=== CONT TestService_cleanupPendingClosuresHandler927=== NAME TestNARDeduplicationMetadataUploadBug928 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestNARDeduplicationMetadataUploadBug837969137/001/store/yfx52kcixhsv02f88lgz9kfwdy0mszq3-file1.txt9292026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes9302026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9312026/10/08 17:08:18 INFO Uploading yfx52kcixhsv02f88lgz9kfwdy0mszq3-file1.txt (160B)9322026/10/08 17:08:18 WARN Failed to register uploaded object key=yfx52kcixhsv02f88lgz9kfwdy0mszq3.ls error="server returned 404: 404 page not found\n"9332026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9342026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9352026/10/08 17:08:18 INFO Signed narinfos id=1 count=19362026/10/08 17:08:18 INFO Uploading 1 narinfos9372026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete9392026/10/08 17:08:18 WARN Failed to register uploaded object key=yfx52kcixhsv02f88lgz9kfwdy0mszq3.narinfo error="server returned 404: 404 page not found\n"9402026/10/08 17:08:19 INFO Completed push id=1 objects=3 duration=29.269375ms9412026/10/08 17:08:19 INFO Upload complete. (170ms)942 metadata_upload_test.go:54: Retrieved narinfo from S3:943 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestNARDeduplicationMetadataUploadBug837969137/001/store/yfx52kcixhsv02f88lgz9kfwdy0mszq3-file1.txt944 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst945 Compression: zstd946 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf947 NarSize: 160948 References: 949 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf950 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)951 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):952 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9532026/10/08 17:08:19 INFO Received uploads request method=POST path=/api/pending_closures954 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/7db02954dc0d9130/build/TestNARDeduplicationMetadataUploadBug837969137/001/store/qf0pnymqhy6dzqspd9rwrbsv23l5ij0z-file2.txt9552026/10/08 17:08:19 INFO Received push request method=POST path=/api/pushes9562026/10/08 17:08:19 INFO Received push request method=POST path=/api/pushes9572026/10/08 17:08:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9582026/10/08 17:08:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9592026/10/08 17:08:19 WARN Failed to register uploaded object key=qf0pnymqhy6dzqspd9rwrbsv23l5ij0z.ls error="server returned 404: 404 page not found\n"9602026/10/08 17:08:19 INFO Signed narinfos id=2 count=19612026/10/08 17:08:19 INFO Uploading 1 narinfos9622026/10/08 17:08:19 INFO Received complete push request method=POST path=/api/pushes/1/complete9632026/10/08 17:08:19 INFO Received complete push request method=POST path=/api/pushes/2/complete9642026/10/08 17:08:19 WARN Failed to register uploaded object key=qf0pnymqhy6dzqspd9rwrbsv23l5ij0z.narinfo error="server returned 404: 404 page not found\n"9652026/10/08 17:08:19 INFO Completed push id=2 objects=3 duration=689.833µs9662026/10/08 17:08:19 INFO Upload complete. (201ms)9672026/10/08 17:08:19 INFO Completed push id=1 objects=4 duration=38.532208ms968--- PASS: TestPush_RepeatedRootCommitsOnce (4.06s)969=== CONT TestUploadHandlersRejectOversizedBody970=== NAME TestNARDeduplicationMetadataUploadBug971 metadata_upload_test.go:76: Retrieved narinfo from S3:972 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestNARDeduplicationMetadataUploadBug837969137/001/store/qf0pnymqhy6dzqspd9rwrbsv23l5ij0z-file2.txt973 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst974 Compression: zstd975 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf976 NarSize: 160977 References: 978 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf979 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)980 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):981 {"version":1,"root":{"type":"regular","size":44}}982=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure983=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure984=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart985=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart986=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts987=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts988=== CONT TestUploadHandlersRejectInvalidKeys989=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info990=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info991=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal992=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal993=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key994=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key995=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key996=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key997=== CONT TestObjectStatsTrigger998--- PASS: TestNARDeduplicationMetadataUploadBug (4.14s)999=== CONT TestReadProxyInvalidPath1000--- PASS: TestReadProxyNarinfoAlreadyDecompressed (4.21s)1001=== CONT TestSkippedUploadsHandler10022026/10/08 17:08:19 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001003--- PASS: TestSkippedUploadsHandler (0.00s)1004=== CONT TestPendingClosureWriteTimeout1005=== RUN TestPendingClosureWriteTimeout/empty1006=== PAUSE TestPendingClosureWriteTimeout/empty1007=== RUN TestPendingClosureWriteTimeout/400_objects1008=== PAUSE TestPendingClosureWriteTimeout/400_objects1009=== RUN TestPendingClosureWriteTimeout/670k_objects1010=== PAUSE TestPendingClosureWriteTimeout/670k_objects1011=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1012=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1013=== CONT TestProxyWriteTimeout1014=== RUN TestProxyWriteTimeout/narinfo1015=== PAUSE TestProxyWriteTimeout/narinfo1016=== RUN TestProxyWriteTimeout/1_GiB_nar1017=== PAUSE TestProxyWriteTimeout/1_GiB_nar1018=== RUN TestProxyWriteTimeout/10_GiB_nar1019=== PAUSE TestProxyWriteTimeout/10_GiB_nar1020=== RUN TestProxyWriteTimeout/unknown_size1021=== PAUSE TestProxyWriteTimeout/unknown_size1022=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10232026/10/08 17:08:19 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1024--- PASS: TestReadProxyNarinfo (4.51s)1025=== CONT TestPresentRefreshesOnlyStaleClosures10262026/10/08 17:08:19 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/08 17:08:20 INFO Received push request method=POST path=/api/pushes1028--- PASS: TestReadRedirectNar (5.32s)1029=== CONT TestPresentReportsOnlyClosureRoots10302026-10-08 17:08:20.669 UTC [74847] ERROR: Push does not exist: id=110312026-10-08 17:08:20.669 UTC [74847] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10322026-10-08 17:08:20.669 UTC [74847] STATEMENT: SELECT commit_push($1)1033--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (5.39s)1034=== CONT TestCreatePin_ReservedPins10352026/10/08 17:08:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54890/oidc10362026/10/08 17:08:20 INFO Received push request method=POST path=/api/pushes10372026/10/08 17:08:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10382026-10-08 17:08:21.062 UTC [74853] ERROR: could not obtain lock on row in relation "closures"10392026-10-08 17:08:21.062 UTC [74853] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10402026-10-08 17:08:21.071 UTC [74853] ERROR: could not obtain lock on row in relation "closures"10412026-10-08 17:08:21.071 UTC [74853] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10422026-10-08 17:08:21.081 UTC [74853] ERROR: could not obtain lock on row in relation "closures"10432026-10-08 17:08:21.081 UTC [74853] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10442026-10-08 17:08:21.086 UTC [74853] ERROR: could not obtain lock on row in relation "closures"10452026-10-08 17:08:21.086 UTC [74853] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10462026-10-08 17:08:21.092 UTC [74853] ERROR: could not obtain lock on row in relation "closures"10472026-10-08 17:08:21.092 UTC [74853] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1048--- PASS: TestPush_RootsAreLockedInByteOrder (5.84s)1049=== CONT TestOrphanedObjectsGCStressTest10502026/10/08 17:08:21 INFO Received push request method=POST path=/api/pushes10512026/10/08 17:08:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjI1ZjIzMTVlLTY1NTQtNGQ2OC1hNzkzLWYyMWU3YTUxNTMxNHgxNzkxNDc5Mjk5MDExNTM3MDAw parts=1210522026/10/08 17:08:21 INFO Received uploads request method=POST path=/api/pending_closures10532026/10/08 17:08:21 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/08 17:08:21 INFO Received complete push request method=POST path=/api/pushes/1/complete10552026/10/08 17:08:21 INFO Completed push id=1 objects=6 duration=38.875042ms1056--- PASS: TestPush_CompleteCommitsEveryRoot (6.07s)1057=== CONT TestOrphanedObjectsGC1058--- PASS: TestReadRedirectUsesPublicS3URL (6.26s)1059=== CONT TestObjectStatsLargeCommit10602026/10/08 17:08:21 INFO Received push request method=POST path=/api/pushes1061--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (6.75s)1062=== CONT TestService_Rustfstest1063--- PASS: TestReadRedirectKeepsNarinfoProxied (6.88s)1064=== CONT TestParseSize1065--- PASS: TestParseSize (0.00s)1066=== CONT TestPinProtectsFromGC10672026/10/08 17:08:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10682026/10/08 17:08:22 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjljNDhkMWU3LWU2YjQtNDZiNC04Y2QyLWZjMGJhY2FiOGQ5YXgxNzkxNDc5MzAwMDU4OTU1MDAw parts=1210692026/10/08 17:08:22 INFO Received uploads request method=POST path=/api/pending_closures1070--- PASS: TestCompletedNarNotReofferedAcrossClosures (7.08s)1071=== CONT TestDeduplicatedObjectsRecordedAsPending10722026/10/08 17:08:22 INFO Received push request method=POST path=/api/pushes10732026/10/08 17:08:22 INFO Received complete push request method=POST path=/api/pushes/1/complete10742026/10/08 17:08:22 INFO Completed push id=1 objects=4 duration=55.995333ms10752026/10/08 17:08:22 INFO Received push request method=POST path=/api/pushes10762026/10/08 17:08:22 INFO Aborted multipart uploads count=0 kept=01077--- PASS: TestReadProxyDisabled (7.52s)1078=== CONT TestPushDedupSurvivesConcurrentGC10792026/10/08 17:08:22 WARN Force mode enabled - objects will be deleted immediately without grace period10802026/10/08 17:08:22 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=010812026/10/08 17:08:22 INFO Vacuumed table table=pending_closures10822026/10/08 17:08:22 INFO Vacuumed table table=pending_objects10832026/10/08 17:08:22 INFO Vacuumed table table=multipart_uploads10842026/10/08 17:08:23 INFO Vacuumed table table=closures10852026/10/08 17:08:23 INFO Vacuumed table table=objects10862026/10/08 17:08:23 INFO Received complete push request method=POST path=/api/pushes/2/complete10872026/10/08 17:08:23 INFO Completed push id=2 objects=4 duration=11.530667ms1088--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.82s)1089=== CONT TestGCMetrics1090--- PASS: TestReadProxyConditionalGet (6.86s)1091=== CONT TestGCBugBareHashReferences10922026/10/08 17:08:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10932026/10/08 17:08:23 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjA4ZGRlNWFkLWU5ZDktNDUwOC1hMmRmLTEyM2QxZjNiNDIwNngxNzkxNDc5MzAxMjUyNTk3MDAw error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10942026/10/08 17:08:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjE4MWE5NWI3LTJhYjEtNDQ1NC1hM2U5LWNhOTJhNzYwYTRmOXgxNzkxNDc5MzAxMjA0ODk1MDAw parts=1210952026/10/08 17:08:23 INFO Received cleanup request method=DELETE path=/api/pending_closures10962026/10/08 17:08:23 INFO Aborted multipart uploads count=1 kept=01097--- PASS: TestRedundantMultipartUpload (8.71s)1098=== CONT TestGCAdvisoryLockBlocksConcurrentRun1099--- PASS: TestReadProxyRootRedirectsToIndexHTML (7.49s)1100=== CONT TestCreatePendingClosureRejectsOversizedNAR11012026/10/08 17:08:24 INFO Received uploads request method=POST path=/api/pending_closures1102--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1103=== CONT TestCacheConfigHandlerMaxNarSize1104--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1105=== CONT TestGenerateLandingPage1106--- PASS: TestGenerateLandingPage (0.00s)1107=== CONT TestService_readinessHandler1108--- PASS: TestReadProxyHead (6.59s)1109=== CONT TestService_healthCheckHandler11102026/10/08 17:08:24 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (7.07s)1112=== CONT TestGracefulShutdownDrainsInflight11132026/10/08 17:08:24 INFO Starting HTTP server address=127.0.0.1:5495811142026/10/08 17:08:24 INFO Shutdown signal received, draining in-flight requests timeout=10s1115--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1116=== CONT TestLeadEndsOnShutdown11172026/10/08 17:08:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11182026/10/08 17:08:25 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1119--- PASS: TestCompleteMultipartUnregistered (7.13s)1120=== CONT TestLeadIncumbentAnnouncesAtOnce11212026/10/08 17:08:25 INFO Received uploads request method=POST path=/api/pending_closures11222026/10/08 17:08:25 INFO Received uploads request method=POST path=/api/pending_closures11232026/10/08 17:08:25 INFO Received uploads request method=POST path=/api/pending_closures11242026/10/08 17:08:25 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/08 17:08:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11262026/10/08 17:08:26 INFO Aborted multipart uploads count=0 kept=011272026/10/08 17:08:26 INFO Received uploads request method=POST path=/api/pending_closures11282026/10/08 17:08:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11292026/10/08 17:08:26 INFO Aborted multipart uploads count=1 kept=011302026/10/08 17:08:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11312026-10-08 17:08:26.422 UTC [74862] ERROR: Closure does not exist: id=111322026-10-08 17:08:26.422 UTC [74862] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11332026-10-08 17:08:26.422 UTC [74862] STATEMENT: -- name: CommitPendingClosure :one1134 SELECT commit_pending_closure($1::bigint)::bigint1135 1136--- PASS: TestService_cleanupPendingClosuresHandler (7.64s)1137=== CONT TestLeadElectsOneAndHandsOver1138--- PASS: TestObjectStatsTrigger (7.27s)1139=== CONT TestConnectWaitsForAPeerMigration1140--- PASS: TestReadProxyInvalidPath (7.43s)1141=== CONT TestGCTaskStore_Fail1142--- PASS: TestGCTaskStore_Fail (0.00s)1143=== CONT TestGCTaskStore_PhaseUpdates1144--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1145=== CONT TestResolveDBConnectionString1146=== RUN TestResolveDBConnectionString/flag_wins1147=== PAUSE TestResolveDBConnectionString/flag_wins1148=== RUN TestResolveDBConnectionString/file_when_flag_empty1149=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1150=== RUN TestResolveDBConnectionString/missing_file_is_an_error1151=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1152=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1153=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1154=== RUN TestResolveDBConnectionString/nothing_configured1155=== PAUSE TestResolveDBConnectionString/nothing_configured1156=== CONT TestGCTaskStore_CompletedAllowsNewTask1157--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1158=== CONT TestGCTaskStore_GetReturnsLatest1159--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1160=== CONT TestClientFallsBackToClosures11612026/10/08 17:08:27 INFO Received uploads request method=POST path=/api/pending_closures1162--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.17s)1163=== CONT TestGCTaskStore_GetEmpty1164--- PASS: TestGCTaskStore_GetEmpty (0.00s)1165=== CONT TestGCTaskStore_ConflictDifferentParams1166--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1167=== CONT TestGCTaskStore_DeduplicateSameParams1168--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1169=== CONT TestDeleteClosuresRacingPins11702026/10/08 17:08:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1171--- PASS: TestPresentRefreshesOnlyStaleClosures (7.91s)1172=== CONT TestClientPushesUseOnePush11732026/10/08 17:08:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11742026/10/08 17:08:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjI5ODg1MzU5LWUxOTktNGE4Ny1hZjk0LWM5YzQ4YzYxMzUwNngxNzkxNDc5MzA1NDk2Mzc3MDAw parts=1011752026/10/08 17:08:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11762026/10/08 17:08:27 INFO Completed upload id=1 objects=2 duration=23.631958ms11772026/10/08 17:08:27 INFO Received uploads request method=POST path=/api/pending_closures11782026/10/08 17:08:27 INFO Received uploads request method=POST path=/api/pending_closures11792026/10/08 17:08:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11802026/10/08 17:08:27 WARN Found objects in DB but missing from S3, will re-upload count=11181--- PASS: TestService_verifyS3Integrity (9.80s)1182=== CONT TestGCTaskStore_StartNew1183--- PASS: TestGCTaskStore_StartNew (0.00s)1184=== CONT TestPresignedUploadRegisteredBeforeCommit11852026/10/08 17:08:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11862026/10/08 17:08:28 WARN Refused reserved pin name=worker-x86_64-linux11872026/10/08 17:08:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11882026/10/08 17:08:28 INFO Received create pin request method=POST path=/api/pins/my-app11892026/10/08 17:08:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1190--- PASS: TestCreatePin_ReservedPins (7.39s)1191=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11922026/10/08 17:08:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11932026/10/08 17:08:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODdlOTk2NTQtOTZmZS00MWNjLTk0NDAtOTQyZTViMWJlNzNiLjFjNmUwYzAyLWVkOTMtNGU2OS1iODI4LTZmNzhhODI5YmMyZXgxNzkxNDc5MzA1OTAxODkwMDAw parts=1011942026/10/08 17:08:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11952026/10/08 17:08:28 INFO Completed upload id=1 objects=2 duration=17.33ms11962026/10/08 17:08:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011972026/10/08 17:08:28 INFO Received uploads request method=POST path=/api/pending_closures11982026/10/08 17:08:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures11992026/10/08 17:08:28 INFO Aborted multipart uploads count=0 kept=012002026/10/08 17:08:28 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=012012026/10/08 17:08:28 INFO Vacuumed table table=pending_closures12022026/10/08 17:08:28 INFO Vacuumed table table=pending_objects1203--- PASS: TestPresentReportsOnlyClosureRoots (7.85s)1204=== CONT TestSweepSkipsRowsLockedByPush12052026/10/08 17:08:28 INFO Vacuumed table table=multipart_uploads12062026/10/08 17:08:28 INFO Vacuumed table table=closures12072026/10/08 17:08:28 INFO Vacuumed table table=objects12082026/10/08 17:08:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001209--- PASS: TestService_createPendingClosureHandler (10.13s)1210=== CONT TestGCEndsOnShutdown1211=== RUN TestGCEndsOnShutdown/before_the_run1212=== PAUSE TestGCEndsOnShutdown/before_the_run1213=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1214=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1215=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1216=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1217=== CONT TestCommitRacingPendingCleanupKeepsObjects1218=== NAME TestOrphanedObjectsGC1219 orphaned_objects_gc_test.go:287: GC Test Summary:1220 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1221 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1222 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1223 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1224 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1225--- PASS: TestOrphanedObjectsGC (8.76s)1226=== CONT TestFailedS3DeleteKeepsTombstone1227--- PASS: TestService_Rustfstest (8.16s)1228=== CONT TestForceGCDuringPushOffersSweptObject1229=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1230=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1231=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1232=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1233=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1234=== NAME TestPinProtectsFromGC1235 client_integration_test.go:731: Pinned store path: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestPinProtectsFromGC2216099260/001/store/cniba27b4zjbvgz6w5ky6axkccjba7w6-pinned-file.txt1236 client_integration_test.go:732: Unpinned store path: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestPinProtectsFromGC2216099260/001/store/kry68372cwrdpmw9y0j0kc9kvmlpf1wm-unpinned-file.txt12372026/10/08 17:08:30 INFO Received push request method=POST path=/api/pushes12382026/10/08 17:08:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12392026/10/08 17:08:30 INFO Uploading cniba27b4zjbvgz6w5ky6axkccjba7w6-pinned-file.txt (128B)12402026/10/08 17:08:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12412026/10/08 17:08:30 WARN Failed to register uploaded object key=cniba27b4zjbvgz6w5ky6axkccjba7w6.ls error="server returned 404: 404 page not found\n"12422026/10/08 17:08:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12432026/10/08 17:08:30 INFO Signed narinfos id=1 count=112442026/10/08 17:08:30 INFO Uploading 1 narinfos12452026/10/08 17:08:30 INFO Received complete push request method=POST path=/api/pushes/1/complete12462026/10/08 17:08:30 WARN Failed to register uploaded object key=cniba27b4zjbvgz6w5ky6axkccjba7w6.narinfo error="server returned 404: 404 page not found\n"12472026/10/08 17:08:30 INFO Received uploads request method=POST path=/api/pending_closures12482026/10/08 17:08:30 INFO Completed push id=1 objects=3 duration=35.967208ms12492026/10/08 17:08:30 INFO Upload complete. (239ms)1250--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.23s)1251=== CONT TestCacheStatsHandler12522026/10/08 17:08:30 INFO Received push request method=POST path=/api/pushes12532026/10/08 17:08:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12542026/10/08 17:08:30 INFO Uploading kry68372cwrdpmw9y0j0kc9kvmlpf1wm-unpinned-file.txt (128B)12552026/10/08 17:08:30 WARN Failed to register uploaded object key=kry68372cwrdpmw9y0j0kc9kvmlpf1wm.ls error="server returned 404: 404 page not found\n"12562026/10/08 17:08:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12572026/10/08 17:08:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12582026/10/08 17:08:30 INFO Signed narinfos id=2 count=112592026/10/08 17:08:30 INFO Uploading 1 narinfos12602026/10/08 17:08:30 INFO Received complete push request method=POST path=/api/pushes/2/complete12612026/10/08 17:08:30 WARN Failed to register uploaded object key=kry68372cwrdpmw9y0j0kc9kvmlpf1wm.narinfo error="server returned 404: 404 page not found\n"12622026/10/08 17:08:30 INFO Completed push id=2 objects=3 duration=846.209µs12632026/10/08 17:08:30 INFO Upload complete. (114ms)12642026/10/08 17:08:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures12652026/10/08 17:08:30 INFO Garbage collection started12662026/10/08 17:08:30 INFO Aborted multipart uploads count=0 kept=012672026/10/08 17:08:30 WARN Force mode enabled - objects will be deleted immediately without grace period12682026/10/08 17:08:30 WARN Rate limiter enabled after throttle name=s3-test rate=512692026/10/08 17:08:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1270=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1271 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101272 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001273--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.31s)1274=== CONT TestPushWaitsForSweepHoldingRow12752026/10/08 17:08:30 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=012762026/10/08 17:08:30 INFO Vacuumed table table=pending_closures12772026/10/08 17:08:30 INFO Vacuumed table table=pending_objects12782026/10/08 17:08:30 INFO Vacuumed table table=multipart_uploads12792026/10/08 17:08:30 INFO Vacuumed table table=closures12802026/10/08 17:08:30 INFO Received uploads request method=POST path=/api/pending_closures12812026/10/08 17:08:31 INFO Vacuumed table table=objects12822026/10/08 17:08:31 INFO Aborted multipart uploads count=0 kept=012832026/10/08 17:08:31 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=012842026/10/08 17:08:31 INFO Vacuumed table table=pending_closures12852026/10/08 17:08:31 INFO Aborted multipart uploads count=0 kept=012862026/10/08 17:08:31 INFO Vacuumed table table=pending_objects12872026/10/08 17:08:31 INFO Vacuumed table table=multipart_uploads12882026/10/08 17:08:31 WARN Force mode enabled - objects will be deleted immediately without grace period12892026/10/08 17:08:31 INFO Vacuumed table table=closures12902026/10/08 17:08:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012912026/10/08 17:08:31 INFO Vacuumed table table=pending_closures12922026/10/08 17:08:31 INFO Vacuumed table table=pending_objects12932026/10/08 17:08:31 INFO Vacuumed table table=objects12942026/10/08 17:08:31 INFO Vacuumed table table=multipart_uploads12952026/10/08 17:08:31 INFO Vacuumed table table=closures12962026/10/08 17:08:31 INFO Vacuumed table table=objects1297--- PASS: TestGCMetrics (8.22s)12982026/10/08 17:08:31 INFO Aborted multipart uploads count=0 kept=01299=== CONT TestSweepRechecksPendingAfterLocking13002026/10/08 17:08:31 WARN Force mode enabled - objects will be deleted immediately without grace period13012026/10/08 17:08:31 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=013022026/10/08 17:08:31 INFO Vacuumed table table=pending_closures13032026/10/08 17:08:31 INFO Vacuumed table table=pending_objects13042026/10/08 17:08:31 INFO Vacuumed table table=multipart_uploads13052026/10/08 17:08:31 INFO Vacuumed table table=closures13062026/10/08 17:08:31 INFO Vacuumed table table=objects1307--- PASS: TestPushDedupSurvivesConcurrentGC (8.59s)1308=== CONT TestGetExistingObjectsLocksRows1309--- PASS: TestGCBugBareHashReferences (8.20s)1310=== CONT TestGCSweepDeliversEachKeyOnce13112026/10/08 17:08:31 WARN readiness check failed error="closed pool"1312--- PASS: TestService_readinessHandler (7.85s)1313=== CONT TestRegisterCompletedObjectNeedsPendingRow13142026/10/08 17:08:32 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1315--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (8.35s)1316=== CONT TestTombstonedObjectOfferedWithoutWaiting1317--- PASS: TestService_healthCheckHandler (8.25s)1318=== CONT TestClientSharedPathCommittedMidPush13192026/10/08 17:08:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013202026/10/08 17:08:32 INFO Received create pin request method=POST path=/api/pins/myapp13212026/10/08 17:08:32 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestPinProtectsFromGC2216099260/001/store/cniba27b4zjbvgz6w5ky6axkccjba7w6-pinned-file.txt narinfo_key=cniba27b4zjbvgz6w5ky6axkccjba7w6.narinfo13222026/10/08 17:08:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures13232026/10/08 17:08:32 INFO Garbage collection started13242026/10/08 17:08:32 INFO Aborted multipart uploads count=0 kept=013252026/10/08 17:08:32 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/08 17:08:32 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=013272026/10/08 17:08:32 INFO Vacuumed table table=pending_closures13282026/10/08 17:08:32 INFO Vacuumed table table=pending_objects13292026/10/08 17:08:32 INFO Vacuumed table table=multipart_uploads13302026/10/08 17:08:32 INFO Vacuumed table table=closures13312026/10/08 17:08:32 INFO Vacuumed table table=objects13322026/10/08 17:08:33 INFO lead: acquired remote=192.0.2.1:123413332026/10/08 17:08:33 INFO lead: released remote=192.0.2.1:12341334--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.89s)1335=== CONT TestGCSweepSkipsPendingObjects13362026/10/08 17:08:33 INFO lead: acquired remote=192.0.2.1:123413372026/10/08 17:08:33 INFO lead: acquired remote=192.0.2.1:123413382026/10/08 17:08:34 INFO lead: released remote=192.0.2.1:12341339--- PASS: TestLeadEndsOnShutdown (9.42s)1340=== CONT TestClientWithDependencies1341=== NAME TestPinProtectsFromGC1342 client_integration_test.go:840: Pin successfully protected closure from garbage collection13432026/10/08 17:08:34 INFO Received uploads request method=POST path=/api/pending_closures13442026/10/08 17:08:34 INFO Received uploads request method=POST path=/api/pending_closures13452026/10/08 17:08:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13462026/10/08 17:08:34 INFO Uploading lcbkdrcyzr0y5dvdsvak6v4w2km30xnw-shared-dep (136B)13472026/10/08 17:08:34 INFO Uploading sypn2a7cvpmdfqr7dydhhhnmdapy9cnx-b (256B)13482026/10/08 17:08:34 WARN Failed to register uploaded object key=fy04iy10ggs19bjbimlwanlmc55qw9ji.ls error="server returned 404: 404 page not found\n"13492026/10/08 17:08:34 WARN Failed to register uploaded object key=lcbkdrcyzr0y5dvdsvak6v4w2km30xnw.ls error="server returned 404: 404 page not found\n"13502026/10/08 17:08:34 WARN Failed to register uploaded object key=nar/15qhc9ax9lza2wnnycj5jii7pq62nd85f2d68zj2r56hy6sh7k1s.nar.zst error="server returned 404: 404 page not found\n"13512026/10/08 17:08:34 WARN Failed to register uploaded object key=sypn2a7cvpmdfqr7dydhhhnmdapy9cnx.ls error="server returned 404: 404 page not found\n"13522026/10/08 17:08:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13532026/10/08 17:08:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13542026/10/08 17:08:35 INFO Signed narinfos id=2 count=213552026/10/08 17:08:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13562026/10/08 17:08:35 INFO Signed narinfos id=1 count=213572026/10/08 17:08:35 INFO Uploading 4 narinfos1358--- PASS: TestPinProtectsFromGC (12.84s)1359=== CONT TestService_ReadScope_PublicByDefault13602026/10/08 17:08:35 WARN Failed to register uploaded object key=fy04iy10ggs19bjbimlwanlmc55qw9ji.narinfo error="server returned 404: 404 page not found\n"13612026/10/08 17:08:35 WARN Failed to register uploaded object key=lcbkdrcyzr0y5dvdsvak6v4w2km30xnw.narinfo error="server returned 404: 404 page not found\n"13622026/10/08 17:08:35 WARN Failed to register uploaded object key=sypn2a7cvpmdfqr7dydhhhnmdapy9cnx.narinfo error="server returned 404: 404 page not found\n"13632026/10/08 17:08:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13642026/10/08 17:08:35 WARN Failed to register uploaded object key=lcbkdrcyzr0y5dvdsvak6v4w2km30xnw.narinfo error="server returned 404: 404 page not found\n"13652026/10/08 17:08:35 INFO lead: released remote=192.0.2.1:123413662026/10/08 17:08:35 INFO Completed upload id=1 objects=6 duration=34.773292ms13672026/10/08 17:08:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13682026/10/08 17:08:35 INFO Completed upload id=2 objects=6 duration=683.75µs13692026/10/08 17:08:35 INFO Upload complete. (401ms)1370=== NAME TestClientFallsBackToClosures1371 client_pushes_test.go:112: Retrieved narinfo from S3:1372 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientFallsBackToClosures1650425442/001/store/lcbkdrcyzr0y5dvdsvak6v4w2km30xnw-shared-dep1373 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1374 Compression: zstd1375 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821376 NarSize: 1361377 References: 1378 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1379 client_pushes_test.go:112: Retrieved narinfo from S3:13802026/10/08 17:08:35 INFO lead: acquired remote=192.0.2.1:12341381 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientFallsBackToClosures1650425442/001/store/fy04iy10ggs19bjbimlwanlmc55qw9ji-a1382 URL: nar/15qhc9ax9lza2wnnycj5jii7pq62nd85f2d68zj2r56hy6sh7k1s.nar.zst1383 Compression: zstd1384 NarHash: sha256:15qhc9ax9lza2wnnycj5jii7pq62nd85f2d68zj2r56hy6sh7k1s1385 NarSize: 2561386 References: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientFallsBackToClosures1650425442/001/store/lcbkdrcyzr0y5dvdsvak6v4w2km30xnw-shared-dep1387 CA: text:sha256:0h396dym2iwbph9iw8fnvffvkg4rsnr7m1x7pl04knn41glplg3v1388 client_pushes_test.go:112: Retrieved narinfo from S3:1389 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientFallsBackToClosures1650425442/001/store/sypn2a7cvpmdfqr7dydhhhnmdapy9cnx-b1390 URL: nar/15qhc9ax9lza2wnnycj5jii7pq62nd85f2d68zj2r56hy6sh7k1s.nar.zst1391 Compression: zstd1392 NarHash: sha256:15qhc9ax9lza2wnnycj5jii7pq62nd85f2d68zj2r56hy6sh7k1s1393 NarSize: 2561394 References: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientFallsBackToClosures1650425442/001/store/lcbkdrcyzr0y5dvdsvak6v4w2km30xnw-shared-dep1395 CA: text:sha256:0h396dym2iwbph9iw8fnvffvkg4rsnr7m1x7pl04knn41glplg3v1396--- PASS: TestClientFallsBackToClosures (8.41s)1397=== CONT TestClientMultipleUploads13982026/10/08 17:08:35 INFO Received uploads request method=POST path=/api/pending_closures13992026/10/08 17:08:35 INFO Received push request method=POST path=/api/pushes14002026/10/08 17:08:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14012026/10/08 17:08:35 INFO Uploading 58nacdvfpqgrjgklxriimc90qqjmscci-shared-dep (136B)14022026/10/08 17:08:35 INFO Uploading 122i234lxxck4dm8qdmnmk8gqf072mkj-a (256B)14032026/10/08 17:08:35 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14042026/10/08 17:08:35 INFO Received uploads request method=POST path=/api/pending_closures1405--- PASS: TestPresignedUploadRegisteredBeforeCommit (7.53s)1406=== CONT TestCacheConfigHandler1407=== RUN TestCacheConfigHandler/full_config,_no_issuer1408=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1409=== RUN TestCacheConfigHandler/no_cache_url_configured1410=== PAUSE TestCacheConfigHandler/no_cache_url_configured1411=== RUN TestCacheConfigHandler/no_signing_keys1412=== PAUSE TestCacheConfigHandler/no_signing_keys1413=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1414=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1415=== CONT TestService_AuthMiddleware_OIDC14162026/10/08 17:08:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14172026/10/08 17:08:35 WARN Failed to register uploaded object key=122i234lxxck4dm8qdmnmk8gqf072mkj.ls error="server returned 404: 404 page not found\n"14182026/10/08 17:08:35 WARN Failed to register uploaded object key=58nacdvfpqgrjgklxriimc90qqjmscci.ls error="server returned 404: 404 page not found\n"14192026/10/08 17:08:35 WARN Failed to register uploaded object key=pi5sgc9szfh5c93xvrwcfmhc3mqa44zq.ls error="server returned 404: 404 page not found\n"14202026/10/08 17:08:35 WARN Failed to register uploaded object key=nar/1bqdsgs60fd4dp8fphh3kmd0vxplc6qd79rgvra14ixcc6892sfi.nar.zst error="server returned 404: 404 page not found\n"14212026/10/08 17:08:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14222026/10/08 17:08:35 INFO Signed narinfos id=1 count=314232026/10/08 17:08:35 INFO Uploading 3 narinfos14242026/10/08 17:08:35 WARN Failed to register uploaded object key=58nacdvfpqgrjgklxriimc90qqjmscci.narinfo error="server returned 404: 404 page not found\n"14252026/10/08 17:08:35 WARN Failed to register uploaded object key=pi5sgc9szfh5c93xvrwcfmhc3mqa44zq.narinfo error="server returned 404: 404 page not found\n"14262026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55082/oidc14272026/10/08 17:08:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14282026/10/08 17:08:35 WARN Failed to register uploaded object key=122i234lxxck4dm8qdmnmk8gqf072mkj.narinfo error="server returned 404: 404 page not found\n"14292026/10/08 17:08:35 INFO Completed push id=1 objects=8 duration=30.027375ms14302026/10/08 17:08:35 INFO Upload complete. (264ms)1431=== NAME TestClientPushesUseOnePush1432 client_pushes_test.go:97: Retrieved narinfo from S3:1433 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientPushesUseOnePush2473019952/001/store/58nacdvfpqgrjgklxriimc90qqjmscci-shared-dep1434 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1435 Compression: zstd1436 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821437 NarSize: 1361438 References: 1439 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1440 client_pushes_test.go:97: Retrieved narinfo from S3:1441 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientPushesUseOnePush2473019952/001/store/122i234lxxck4dm8qdmnmk8gqf072mkj-a1442 URL: nar/1bqdsgs60fd4dp8fphh3kmd0vxplc6qd79rgvra14ixcc6892sfi.nar.zst1443 Compression: zstd1444 NarHash: sha256:1bqdsgs60fd4dp8fphh3kmd0vxplc6qd79rgvra14ixcc6892sfi1445 NarSize: 2561446 References: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientPushesUseOnePush2473019952/001/store/58nacdvfpqgrjgklxriimc90qqjmscci-shared-dep1447 CA: text:sha256:0mf7nhndfr0a88x5rrxdm7kp1aqjsjsx4mxk268zrydfvsq0hg8w1448 client_pushes_test.go:97: Retrieved narinfo from S3:1449 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientPushesUseOnePush2473019952/001/store/pi5sgc9szfh5c93xvrwcfmhc3mqa44zq-b1450 URL: nar/1bqdsgs60fd4dp8fphh3kmd0vxplc6qd79rgvra14ixcc6892sfi.nar.zst1451 Compression: zstd1452 NarHash: sha256:1bqdsgs60fd4dp8fphh3kmd0vxplc6qd79rgvra14ixcc6892sfi1453 NarSize: 2561454 References: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientPushesUseOnePush2473019952/001/store/58nacdvfpqgrjgklxriimc90qqjmscci-shared-dep1455 CA: text:sha256:0mf7nhndfr0a88x5rrxdm7kp1aqjsjsx4mxk268zrydfvsq0hg8w1456--- PASS: TestConnectWaitsForAPeerMigration (9.10s)1457=== CONT TestClientIntegration1458--- PASS: TestClientPushesUseOnePush (8.01s)1459=== CONT TestService_RequireScope_OIDC14602026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55086/oidc14612026/10/08 17:08:36 INFO lead: released remote=192.0.2.1:12341462--- PASS: TestLeadElectsOneAndHandsOver (9.81s)1463=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14642026/10/08 17:08:36 INFO Aborted multipart uploads count=0 kept=014652026/10/08 17:08:36 WARN Force mode enabled - objects will be deleted immediately without grace period14662026/10/08 17:08:36 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=014672026/10/08 17:08:36 INFO Vacuumed table table=pending_closures14682026/10/08 17:08:36 INFO Vacuumed table table=pending_objects14692026/10/08 17:08:36 INFO Vacuumed table table=multipart_uploads14702026/10/08 17:08:36 INFO Vacuumed table table=closures14712026/10/08 17:08:36 INFO Vacuumed table table=objects14722026/10/08 17:08:36 INFO Aborted multipart uploads count=0 kept=014732026/10/08 17:08:36 WARN Force mode enabled - objects will be deleted immediately without grace period14742026/10/08 17:08:36 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=014752026/10/08 17:08:36 INFO Vacuumed table table=pending_closures14762026/10/08 17:08:36 INFO Vacuumed table table=pending_objects14772026/10/08 17:08:36 INFO Vacuumed table table=multipart_uploads14782026/10/08 17:08:36 INFO Vacuumed table table=closures14792026/10/08 17:08:36 INFO Vacuumed table table=objects1480--- PASS: TestSweepSkipsRowsLockedByPush (8.09s)1481=== CONT TestClientErrorHandling1482=== RUN TestClientErrorHandling/InvalidStorePath1483=== PAUSE TestClientErrorHandling/InvalidStorePath1484=== RUN TestClientErrorHandling/InvalidAuthToken1485=== PAUSE TestClientErrorHandling/InvalidAuthToken1486=== RUN TestClientErrorHandling/ServerNotAvailable1487=== PAUSE TestClientErrorHandling/ServerNotAvailable1488=== CONT TestServerTLSConfig1489=== RUN TestServerTLSConfig/no_client_CA1490=== PAUSE TestServerTLSConfig/no_client_CA1491=== RUN TestServerTLSConfig/missing_CA_file1492=== PAUSE TestServerTLSConfig/missing_CA_file1493=== RUN TestServerTLSConfig/not_a_PEM_file1494=== PAUSE TestServerTLSConfig/not_a_PEM_file1495=== CONT TestService_ReadAuthMiddleware14962026/10/08 17:08:36 INFO Aborted multipart uploads count=0 kept=01497=== NAME TestOrphanedObjectsGCStressTest1498 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14992026/10/08 17:08:36 WARN Force mode enabled - objects will be deleted immediately without grace period15002026/10/08 17:08:36 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=01501 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion15022026/10/08 17:08:37 INFO Vacuumed table table=pending_closures15032026/10/08 17:08:37 INFO Vacuumed table table=pending_objects15042026/10/08 17:08:37 INFO Vacuumed table table=multipart_uploads15052026/10/08 17:08:37 INFO Received uploads request method=POST path=/api/pending_closures15062026/10/08 17:08:37 INFO Vacuumed table table=closures15072026/10/08 17:08:37 INFO Vacuumed table table=objects1508--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.53s)1509=== CONT TestClientCADerivations1510--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (7.11s)1511=== CONT TestMetricsCommit1512--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (9.33s)1513=== CONT TestService_NativeMTLS15142026/10/08 17:08:37 INFO Received uploads request method=POST path=/api/pending_closures15152026/10/08 17:08:37 INFO Aborted multipart uploads count=0 kept=015162026/10/08 17:08:37 WARN Force mode enabled - objects will be deleted immediately without grace period15172026/10/08 17:08:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15182026/10/08 17:08:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1519--- PASS: TestFailedS3DeleteKeepsTombstone (7.74s)1520=== CONT TestPendingCleanupUsesOneCutoff1521--- PASS: TestCacheStatsHandler (7.39s)1522=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded15232026/10/08 17:08:38 INFO Received uploads request method=POST path=/api/pending_closures1524--- PASS: TestGetExistingObjectsLocksRows (7.48s)1525=== CONT TestMultipartCleanup1526--- PASS: TestPushWaitsForSweepHoldingRow (8.13s)1527=== CONT TestService_AuthMiddleware_MTLSProxyHeader15282026/10/08 17:08:39 INFO Aborted multipart uploads count=0 kept=015292026/10/08 17:08:39 WARN Force mode enabled - objects will be deleted immediately without grace period15302026/10/08 17:08:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015312026/10/08 17:08:39 INFO Vacuumed table table=pending_closures15322026/10/08 17:08:39 INFO Vacuumed table table=pending_objects15332026/10/08 17:08:39 INFO Vacuumed table table=multipart_uploads15342026/10/08 17:08:39 INFO Vacuumed table table=closures15352026/10/08 17:08:39 INFO Vacuumed table table=objects1536--- PASS: TestSweepRechecksPendingAfterLocking (8.19s)1537=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1538--- PASS: TestRegisterCompletedObjectNeedsPendingRow (7.76s)1539=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15402026/10/08 17:08:40 INFO Aborted multipart uploads count=0 kept=015412026/10/08 17:08:40 WARN Force mode enabled - objects will be deleted immediately without grace period15422026/10/08 17:08:40 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=015432026/10/08 17:08:40 INFO Vacuumed table table=pending_closures15442026/10/08 17:08:40 INFO Vacuumed table table=pending_objects15452026/10/08 17:08:40 INFO Vacuumed table table=multipart_uploads15462026/10/08 17:08:40 INFO Vacuumed table table=closures15472026/10/08 17:08:40 INFO Vacuumed table table=objects1548--- PASS: TestGCSweepDeliversEachKeyOnce (8.43s)1549=== CONT TestParseSingleRange/none1550=== CONT TestParseSingleRange/start_far_past_EOF1551=== CONT TestParseSingleRange/start_past_EOF1552=== CONT TestParseSingleRange/single_byte1553=== CONT TestParseSingleRange/suffix_exceeds_size1554=== CONT TestParseSingleRange/suffix1555=== CONT TestParseSingleRange/end_clamped_to_size1556=== CONT TestParseSingleRange/open-ended1557=== CONT TestParseSingleRange/closed1558=== CONT TestParseSingleRange/malformed_end_before_start1559=== CONT TestParseSingleRange/malformed_both_empty1560=== CONT TestParseSingleRange/malformed_no_dash1561=== CONT TestParseSingleRange/multi-range_ignored1562=== CONT TestParseSingleRange/unknown_unit1563=== CONT TestIsValidCachePath/narinfo1564--- PASS: TestParseSingleRange (0.01s)1565 --- PASS: TestParseSingleRange/none (0.00s)1566 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1567 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1568 --- PASS: TestParseSingleRange/single_byte (0.00s)1569 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1570 --- PASS: TestParseSingleRange/suffix (0.00s)1571 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1572 --- PASS: TestParseSingleRange/open-ended (0.00s)1573 --- PASS: TestParseSingleRange/closed (0.00s)1574 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1575 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1576 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1577 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1578 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1579=== CONT TestIsValidCachePath/index.html1580=== CONT TestIsValidCachePath/short_hash1581=== CONT TestIsValidCachePath/wrong_extension1582=== CONT TestIsValidCachePath/leading_slash1583=== CONT TestIsValidCachePath/empty1584=== CONT TestIsValidCachePath/nix-cache-info1585=== CONT TestIsValidCachePath/realisation1586=== CONT TestIsValidCachePath/random_path1587=== CONT TestIsValidCachePath/invalid_char_u1588=== CONT TestIsValidCachePath/log1589=== CONT TestIsValidCachePath/ls1590=== CONT TestIsValidCachePath/invalid_char_e1591=== CONT TestIsValidCachePath/traversal_in_middle1592=== CONT TestIsValidCachePath/traversal_parent1593=== CONT TestIsValidCachePath/nar_uncompressed1594=== CONT TestIsValidCachePath/nar_xz1595=== CONT TestIsValidCachePath/nar_zst1596=== CONT TestIsValidCachePath/nar_bz21597=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1598--- PASS: TestIsValidCachePath (0.01s)1599 --- PASS: TestIsValidCachePath/narinfo (0.00s)1600 --- PASS: TestIsValidCachePath/index.html (0.00s)1601 --- PASS: TestIsValidCachePath/short_hash (0.00s)1602 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1603 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1604 --- PASS: TestIsValidCachePath/empty (0.00s)1605 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1606 --- PASS: TestIsValidCachePath/realisation (0.00s)1607 --- PASS: TestIsValidCachePath/random_path (0.00s)1608 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1609 --- PASS: TestIsValidCachePath/log (0.00s)1610 --- PASS: TestIsValidCachePath/ls (0.00s)1611 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1612 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1613 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1614 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1615 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1616 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1617 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1618 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1619=== CONT TestIsValidUploadKey/narinfo1620=== CONT TestIsValidUploadKey/realisation_plus_in_output1621=== CONT TestIsValidUploadKey/unknown_type1622=== CONT TestIsValidUploadKey/empty_key1623=== CONT TestIsValidUploadKey/absolute1624=== CONT TestIsValidUploadKey/traversal_nar1625=== CONT TestIsValidUploadKey/traversal1626=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1627=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1628=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1629=== CONT TestIsValidUploadKey/index.html1630=== CONT TestIsValidUploadKey/nix-cache-info1631=== CONT TestIsValidUploadKey/build_log_home-manager_file1632=== CONT TestIsValidUploadKey/realisation1633=== CONT TestIsValidUploadKey/build_log_equals1634=== CONT TestIsValidUploadKey/build_log_question_mark1635=== CONT TestIsValidUploadKey/build_log_plus_in_name1636=== CONT TestIsValidUploadKey/nar_plain1637=== CONT TestIsValidUploadKey/build_log1638=== CONT TestIsValidUploadKey/listing1639=== CONT TestIsValidUploadKey/nar_xz1640=== CONT TestIsValidUploadKey/nar_zst1641--- PASS: TestIsValidUploadKey (0.01s)1642 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1643 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1644 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1645 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1646 --- PASS: TestIsValidUploadKey/absolute (0.00s)1647 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1648 --- PASS: TestIsValidUploadKey/traversal (0.00s)1649 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1650 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1651 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1652 --- PASS: TestIsValidUploadKey/index.html (0.00s)1653 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1654 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1655 --- PASS: TestIsValidUploadKey/realisation (0.00s)1656 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1657 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1658 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1659 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1660 --- PASS: TestIsValidUploadKey/build_log (0.00s)1661 --- PASS: TestIsValidUploadKey/listing (0.00s)1662 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1663 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1664=== CONT TestPush_RejectsBadRequests/no_objects16652026/10/08 17:08:40 INFO Received push request method=POST path=/api/pushes1666=== CONT TestPush_RejectsBadRequests/no_roots16672026/10/08 17:08:40 INFO Received push request method=POST path=/api/pushes1668=== CONT TestPush_RejectsBadRequests/root_not_in_objects16692026/10/08 17:08:40 INFO Received push request method=POST path=/api/pushes1670=== CONT TestPush_RejectsBadRequests/bad_root16712026/10/08 17:08:40 INFO Received push request method=POST path=/api/pushes1672=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16732026/10/08 17:08:40 INFO Received uploads request method=POST path=/1674--- PASS: TestPush_RejectsBadRequests (3.50s)1675 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1676 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1677 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1678 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)16792026/10/08 17:08:40 INFO Received uploads request method=POST path=/api/pending_closures1680--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.07s)1681=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16822026/10/08 17:08:40 INFO Received request for more parts method=POST path=/1683=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16842026/10/08 17:08:40 INFO Received complete multipart upload request method=POST path=/1685=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16862026/10/08 17:08:40 INFO Received uploads request method=POST path=/1687=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16882026/10/08 17:08:40 INFO Received complete multipart upload request method=POST path=/1689=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16902026/10/08 17:08:40 INFO Received uploads request method=POST path=/1691=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16922026/10/08 17:08:40 INFO Received request for more parts method=POST path=/1693--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1694 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1695 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1696 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1697 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1698=== CONT TestPendingClosureWriteTimeout/empty1699=== CONT TestPendingClosureWriteTimeout/670k_objects1700=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1701=== CONT TestPendingClosureWriteTimeout/400_objects1702=== CONT TestProxyWriteTimeout/narinfo1703--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1704 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1705 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1706 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.33s)1707=== CONT TestProxyWriteTimeout/10_GiB_nar1708=== CONT TestProxyWriteTimeout/unknown_size1709=== CONT TestProxyWriteTimeout/1_GiB_nar1710--- PASS: TestProxyWriteTimeout (0.00s)1711 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1712 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1713 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1714 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1715=== CONT TestResolveDBConnectionString/flag_wins1716=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1717=== CONT TestResolveDBConnectionString/nothing_configured1718=== CONT TestResolveDBConnectionString/missing_file_is_an_error1719=== CONT TestResolveDBConnectionString/file_when_flag_empty1720=== CONT TestGCEndsOnShutdown/before_the_run1721--- PASS: TestResolveDBConnectionString (0.03s)1722 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1723 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1724 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1725 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1726 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1727--- PASS: TestObjectStatsLargeCommit (19.19s)1728=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1729--- PASS: TestDeleteClosuresRacingPins (13.38s)1730=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1731{"timestamp":"2026-10-08T17:08:40.925293Z","level":"ERROR","message":"Heal storage request failed","event":"heal_storage_object_io","component":"heal","subsystem":"storage","operation":"object_exists","bucket":".rustfs.sys","object":"buckets/.usage.v2.json","result":"failed","error":"Io error: Too many open files (os error 24)","target":"rustfs::heal::storage","filename":"crates/heal/src/heal/storage.rs","line_number":1339,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}1732{"timestamp":"2026-10-08T17:08:40.925265Z","level":"ERROR","duration":"9.619584ms","resp":"Response { status: 500, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>InternalError</Code><Message>We encountered an internal error, please try again.</Message></Error>\", remaining_limit: None } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-28079-3532540677/rustfs-1.0.0-vendor/source-registry-0/s3s-0.16.0/src/service.rs","line_number":680,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}1733{"timestamp":"2026-10-08T17:08:40.925349Z","level":"ERROR","message":"Heal scheduler task failed","event":"heal_scheduler_state","component":"heal","subsystem":"manager","task_id":"5fdb80eb-c906-47fb-8751-decc17cb51b3","heal_type":"object","set":"pool_0_set_0","state":"task_failed","error":"Other error: Io error: Too many open files (os error 24)","target":"rustfs::heal::manager","filename":"crates/heal/src/heal/manager/scheduler.rs","line_number":269,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}1734{"timestamp":"2026-10-08T17:08:40.925352Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"30813663-e3f2-4cf8-8396-418667c4e0e4","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket76/","status_code":500,"suppressed_errors":0,"duration_ms":9,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}17352026/10/08 17:08:40 INFO Received uploads request method=POST path=/api/pending_closures17362026/10/08 17:08:41 INFO Received push request method=POST path=/api/pushes17372026/10/08 17:08:41 INFO Aborted multipart uploads count=0 kept=017382026/10/08 17:08:41 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17392026/10/08 17:08:41 INFO Uploading dav8045rnxji08zzgkcxrckwh0kb2h5m-shared-dep (136B)17402026/10/08 17:08:41 INFO Uploading 4nrnr2wgaagby21wvjmm3imv3mz742yp-top (264B)17412026/10/08 17:08:41 WARN Force mode enabled - objects will be deleted immediately without grace period17422026/10/08 17:08:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017432026/10/08 17:08:41 WARN Failed to register uploaded object key=dav8045rnxji08zzgkcxrckwh0kb2h5m.ls error="server returned 404: 404 page not found\n"17442026/10/08 17:08:41 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17452026/10/08 17:08:41 WARN Failed to register uploaded object key=nar/12cp2cg3n0x2251bc6zl9x7sgjxgcb85wmr1yfb2m6kj347y3dwh.nar.zst error="server returned 404: 404 page not found\n"17462026/10/08 17:08:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17472026/10/08 17:08:41 WARN Failed to register uploaded object key=4nrnr2wgaagby21wvjmm3imv3mz742yp.ls error="server returned 404: 404 page not found\n"17482026/10/08 17:08:41 INFO Vacuumed table table=pending_closures17492026/10/08 17:08:41 INFO Signed narinfos id=1 count=217502026/10/08 17:08:41 INFO Uploading 2 narinfos1751=== NAME TestOrphanedObjectsGCStressTest1752 orphaned_objects_gc_test.go:503: Stress test completed successfully:1753 orphaned_objects_gc_test.go:504: - Active objects preserved: 201754 orphaned_objects_gc_test.go:505: - Objects deleted: 2101755 orphaned_objects_gc_test.go:506: - Total GC'd: 2101756--- PASS: TestOrphanedObjectsGCStressTest (19.96s)1757=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17582026/10/08 17:08:41 INFO Vacuumed table table=pending_objects17592026/10/08 17:08:41 WARN Failed to register uploaded object key=4nrnr2wgaagby21wvjmm3imv3mz742yp.narinfo error="server returned 404: 404 page not found\n"17602026/10/08 17:08:41 INFO Received complete push request method=POST path=/api/pushes/1/complete17612026/10/08 17:08:41 WARN Failed to register uploaded object key=dav8045rnxji08zzgkcxrckwh0kb2h5m.narinfo error="server returned 404: 404 page not found\n"17622026/10/08 17:08:41 INFO Vacuumed table table=multipart_uploads17632026/10/08 17:08:41 INFO Vacuumed table table=closures17642026/10/08 17:08:41 INFO Completed push id=1 objects=6 duration=30.176167ms17652026/10/08 17:08:41 INFO Upload complete. (240ms)1766=== NAME TestClientSharedPathCommittedMidPush1767 client_integration_test.go:680: Retrieved narinfo from S3:1768 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientSharedPathCommittedMidPush1542958674/001/store/dav8045rnxji08zzgkcxrckwh0kb2h5m-shared-dep1769 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1770 Compression: zstd1771 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821772 NarSize: 1361773 References: 1774 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17752026/10/08 17:08:41 INFO Vacuumed table table=objects1776 client_integration_test.go:680: Retrieved narinfo from S3:1777 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientSharedPathCommittedMidPush1542958674/001/store/4nrnr2wgaagby21wvjmm3imv3mz742yp-top1778 URL: nar/12cp2cg3n0x2251bc6zl9x7sgjxgcb85wmr1yfb2m6kj347y3dwh.nar.zst1779 Compression: zstd1780 NarHash: sha256:12cp2cg3n0x2251bc6zl9x7sgjxgcb85wmr1yfb2m6kj347y3dwh1781 NarSize: 2641782 References: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientSharedPathCommittedMidPush1542958674/001/store/dav8045rnxji08zzgkcxrckwh0kb2h5m-shared-dep1783 CA: text:sha256:1xsq7hrmnpci2qnp1j34h52wn5znfwv8jkq6hk9snxfxb1chgjj71784--- PASS: TestGCSweepSkipsPendingObjects (8.17s)1785=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1786--- PASS: TestClientSharedPathCommittedMidPush (8.55s)1787=== CONT TestCacheConfigHandler/full_config,_no_issuer1788=== CONT TestCacheConfigHandler/no_signing_keys1789=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1790=== CONT TestCacheConfigHandler/no_cache_url_configured1791--- PASS: TestCacheConfigHandler (0.00s)1792 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1793 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1794 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1795 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1796=== CONT TestClientErrorHandling/InvalidStorePath1797--- PASS: TestService_ReadScope_PublicByDefault (6.61s)1798=== CONT TestClientErrorHandling/ServerNotAvailable1799=== NAME TestClientWithDependencies1800 client_integration_test.go:613: Built derivation: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientWithDependencies1129809271/001/store/ld0zv287sl69aqpc57bzhsv5rb4miv6c-test-script1801 client_integration_test.go:615: Found 1 dependencies (including self)18022026/10/08 17:08:41 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/present18032026/10/08 17:08:41 INFO Received push request method=POST path=/api/pushes18042026/10/08 17:08:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18052026/10/08 17:08:42 INFO Uploading ld0zv287sl69aqpc57bzhsv5rb4miv6c-test-script (136B)18062026/10/08 17:08:42 WARN Request failed, retrying attempt=2 backoff=209.34233ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18072026/10/08 17:08:42 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18082026/10/08 17:08:42 WARN Failed to register uploaded object key=ld0zv287sl69aqpc57bzhsv5rb4miv6c.ls error="server returned 404: 404 page not found\n"18092026/10/08 17:08:42 WARN Failed to register uploaded object key=log/vyl3kq1fw1wr1abviwq2rpjp1lsy0z09-test-script.drv error="server returned 404: 404 page not found\n"18102026/10/08 17:08:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18112026/10/08 17:08:42 INFO Signed narinfos id=1 count=118122026/10/08 17:08:42 INFO Uploading 1 narinfos18132026/10/08 17:08:42 INFO Received complete push request method=POST path=/api/pushes/1/complete18142026/10/08 17:08:42 WARN Failed to register uploaded object key=ld0zv287sl69aqpc57bzhsv5rb4miv6c.narinfo error="server returned 404: 404 page not found\n"18152026/10/08 17:08:42 INFO Completed push id=1 objects=4 duration=33.716959ms18162026/10/08 17:08:42 INFO Upload complete. (273ms)1817 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientWithDependencies1129809271/001/store) requires matching store prefix18182026/10/08 17:08:42 WARN Request failed, retrying attempt=3 backoff=364.565635ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1819--- PASS: TestClientWithDependencies (7.86s)1820=== CONT TestClientErrorHandling/InvalidAuthToken1821=== NAME TestClientMultipleUploads1822 client_integration_test.go:358: Created store path 0: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientMultipleUploads2780491776/001/store/9l9mjs5xvgd8mzwwz8p9vzqz1ga8qx49-test-file-0.txt1823=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1824=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1825=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1826=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1827=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1828=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1829=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1830=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1831=== CONT TestServerTLSConfig/no_client_CA1832=== CONT TestServerTLSConfig/not_a_PEM_file1833=== CONT TestServerTLSConfig/missing_CA_file1834--- PASS: TestServerTLSConfig (0.00s)1835 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1836 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.06s)1837 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1838=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1839=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1840=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18412026/10/08 17:08:42 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]1842=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18432026/10/08 17:08:42 WARN Authentication failed token_preview=eyJhbGciOi...1bC0GxD42A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1844--- PASS: TestService_AuthMiddleware_OIDC (6.86s)1845 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1846 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1847 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1848 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1849=== NAME TestClientMultipleUploads1850 client_integration_test.go:358: Created store path 1: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientMultipleUploads2780491776/001/store/y6vy6hn7k6k63p4q70lsqisbmfvpy0q1-test-file-1.txt1851 client_integration_test.go:358: Created store path 2: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientMultipleUploads2780491776/001/store/5qarw609vf4019azd2zhpx21n9gqngar-test-file-2.txt18522026/10/08 17:08:42 WARN Request failed, retrying attempt=4 backoff=871.624259ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18532026/10/08 17:08:42 INFO Received push request method=POST path=/api/pushes18542026/10/08 17:08:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18552026/10/08 17:08:42 INFO Uploading 5qarw609vf4019azd2zhpx21n9gqngar-test-file-2.txt (160B)18562026/10/08 17:08:42 INFO Uploading 9l9mjs5xvgd8mzwwz8p9vzqz1ga8qx49-test-file-0.txt (160B)18572026/10/08 17:08:42 INFO Uploading y6vy6hn7k6k63p4q70lsqisbmfvpy0q1-test-file-1.txt (160B)18582026/10/08 17:08:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18592026/10/08 17:08:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18602026/10/08 17:08:42 WARN Failed to register uploaded object key=5qarw609vf4019azd2zhpx21n9gqngar.ls error="server returned 404: 404 page not found\n"18612026/10/08 17:08:42 WARN Failed to register uploaded object key=9l9mjs5xvgd8mzwwz8p9vzqz1ga8qx49.ls error="server returned 404: 404 page not found\n"18622026/10/08 17:08:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18632026/10/08 17:08:42 WARN Failed to register uploaded object key=y6vy6hn7k6k63p4q70lsqisbmfvpy0q1.ls error="server returned 404: 404 page not found\n"18642026/10/08 17:08:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18652026/10/08 17:08:42 INFO Signed narinfos id=1 count=318662026/10/08 17:08:42 INFO Uploading 3 narinfos18672026/10/08 17:08:42 WARN Failed to register uploaded object key=9l9mjs5xvgd8mzwwz8p9vzqz1ga8qx49.narinfo error="server returned 404: 404 page not found\n"18682026/10/08 17:08:42 INFO Received complete push request method=POST path=/api/pushes/1/complete18692026/10/08 17:08:42 WARN Failed to register uploaded object key=5qarw609vf4019azd2zhpx21n9gqngar.narinfo error="server returned 404: 404 page not found\n"18702026/10/08 17:08:42 WARN Failed to register uploaded object key=y6vy6hn7k6k63p4q70lsqisbmfvpy0q1.narinfo error="server returned 404: 404 page not found\n"18712026/10/08 17:08:42 INFO Completed push id=1 objects=9 duration=41.940458ms18722026/10/08 17:08:42 INFO Upload complete. (291ms)1873 client_integration_test.go:369: Uploaded 3 paths in 327.112167ms1874--- PASS: TestClientMultipleUploads (7.72s)1875=== RUN TestService_RequireScope_OIDC/builder_may_write1876=== PAUSE TestService_RequireScope_OIDC/builder_may_write1877=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1878=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1879=== RUN TestService_RequireScope_OIDC/ops_may_admin1880=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1881=== RUN TestService_RequireScope_OIDC/ops_may_not_write1882=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1883=== RUN TestService_RequireScope_OIDC/reader_may_not_write1884=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1885=== RUN TestService_RequireScope_OIDC/static_token_may_admin1886=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1887=== RUN TestService_RequireScope_OIDC/static_token_may_write1888=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1889=== RUN TestService_RequireScope_OIDC/reader_may_read1890=== PAUSE TestService_RequireScope_OIDC/reader_may_read1891=== RUN TestService_RequireScope_OIDC/writer_implies_read1892=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1893=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1894=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1895=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1896=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1897=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1898=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1899=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1900=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1901=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1902=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1903=== CONT TestService_RequireScope_OIDC/builder_may_write1904=== CONT TestService_RequireScope_OIDC/reader_may_read1905=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1906=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1907=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1908=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1909=== CONT TestService_RequireScope_OIDC/ops_may_admin1910=== CONT TestService_RequireScope_OIDC/writer_implies_read1911=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1912=== CONT TestService_RequireScope_OIDC/ops_may_not_write19132026/10/08 17:08:43 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]1914=== CONT TestService_RequireScope_OIDC/static_token_may_write1915=== CONT TestService_RequireScope_OIDC/static_token_may_admin1916=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1917=== CONT TestService_RequireScope_OIDC/reader_may_not_write1918--- PASS: TestService_RequireScope_OIDC (7.31s)1919 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1933=== NAME TestClientIntegration1934 client_integration_test.go:286: Created store path: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientIntegration2483243699/002/store/8v38a8xqi5snfjxyn6galyhp4xda9hdl-test-file.txt19352026/10/08 17:08:43 INFO Received push request method=POST path=/api/pushes19362026-10-08 17:08:43.237 UTC [74683] LOG: checkpoint starting: wal19372026/10/08 17:08:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19382026/10/08 17:08:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19392026/10/08 17:08:43 WARN mTLS auth: bound subjects configured but subject DN unavailable19402026/10/08 17:08:43 INFO Uploading 8v38a8xqi5snfjxyn6galyhp4xda9hdl-test-file.txt (152B)19412026/10/08 17:08:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1942--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.07s)19432026/10/08 17:08:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19442026/10/08 17:08:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19452026/10/08 17:08:43 WARN Failed to register uploaded object key=8v38a8xqi5snfjxyn6galyhp4xda9hdl.ls error="server returned 404: 404 page not found\n"19462026/10/08 17:08:43 INFO Signed narinfos id=1 count=119472026/10/08 17:08:43 INFO Uploading 1 narinfos19482026/10/08 17:08:43 INFO Received complete push request method=POST path=/api/pushes/1/complete19492026/10/08 17:08:43 WARN Failed to register uploaded object key=8v38a8xqi5snfjxyn6galyhp4xda9hdl.narinfo error="server returned 404: 404 page not found\n"19502026/10/08 17:08:43 INFO Completed push id=1 objects=3 duration=45.33ms19512026/10/08 17:08:43 INFO Upload complete. (297ms)19522026/10/08 17:08:43 WARN Request failed, retrying attempt=5 backoff=1.590092163s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19532026/10/08 17:08:43 INFO All 1 paths already cached1954=== NAME TestClientIntegration1955 client_integration_test.go:312: Retrieved narinfo from S3:1956 StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientIntegration2483243699/002/store/8v38a8xqi5snfjxyn6galyhp4xda9hdl-test-file.txt1957 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1958 Compression: zstd1959 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11960 NarSize: 1521961 References: 1962 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11963 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1964 client_integration_test.go:313: Decompressed .ls content (64 bytes):1965 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1966 client_integration_test.go:316: Testing garbage collection...19672026/10/08 17:08:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures19682026/10/08 17:08:43 INFO Garbage collection started19692026/10/08 17:08:43 INFO Aborted multipart uploads count=0 kept=019702026/10/08 17:08:43 WARN Force mode enabled - objects will be deleted immediately without grace period1971--- PASS: TestService_ReadAuthMiddleware (7.04s)19722026/10/08 17:08:43 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=019732026/10/08 17:08:43 INFO Vacuumed table table=pending_closures19742026/10/08 17:08:43 INFO Vacuumed table table=pending_objects19752026/10/08 17:08:43 INFO Vacuumed table table=multipart_uploads19762026/10/08 17:08:43 INFO Vacuumed table table=closures19772026/10/08 17:08:43 INFO Vacuumed table table=objects1978{"timestamp":"2026-10-08T17:08:43.9637Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":5,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}19792026/10/08 17:08:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19802026/10/08 17:08:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1981--- PASS: TestService_NativeMTLS (6.78s)19822026/10/08 17:08:44 INFO Received push request method=POST path=/api/pushes1983=== NAME TestClientCADerivations1984 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientCADerivations757736768/001/store/j741qmpkbkrlxk6284fjfb5vjlw8hnwh-ca-test19852026/10/08 17:08:44 INFO Received complete push request method=POST path=/api/pushes/1/complete19862026/10/08 17:08:44 INFO Completed push id=1 objects=4 duration=20.888125ms19872026/10/08 17:08:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19882026/10/08 17:08:44 INFO Completed upload id=2 objects=2 duration=322.333µs1989--- PASS: TestMetricsCommit (7.22s)1990=== NAME TestClientCADerivations1991 client_ca_test.go:139: Found 1 dependencies (including self)19922026/10/08 17:08:44 INFO Received uploads request method=POST path=/api/pending_closures19932026/10/08 17:08:44 INFO Received push request method=POST path=/api/pushes19942026/10/08 17:08:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19952026/10/08 17:08:44 INFO Uploading j741qmpkbkrlxk6284fjfb5vjlw8hnwh-ca-test (144B)19962026/10/08 17:08:44 INFO Received uploads request method=POST path=/api/pending_closures19972026/10/08 17:08:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19982026/10/08 17:08:44 WARN Failed to register uploaded object key=log/kdmsjrm681605chqpkyda4qbcqqhgd3m-ca-test.drv error="server returned 404: 404 page not found\n"19992026/10/08 17:08:44 INFO Received cleanup request method=DELETE path=/api/pending_closures20002026/10/08 17:08:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20012026/10/08 17:08:44 WARN Failed to register uploaded object key=j741qmpkbkrlxk6284fjfb5vjlw8hnwh.ls error="server returned 404: 404 page not found\n"20022026/10/08 17:08:44 INFO Signed narinfos id=1 count=120032026/10/08 17:08:44 INFO Uploading 1 narinfos20042026/10/08 17:08:44 INFO Received complete push request method=POST path=/api/pushes/1/complete20052026/10/08 17:08:44 WARN Failed to register uploaded object key=j741qmpkbkrlxk6284fjfb5vjlw8hnwh.narinfo error="server returned 404: 404 page not found\n"20062026/10/08 17:08:44 INFO Completed push id=1 objects=4 duration=18.961125ms20072026/10/08 17:08:44 INFO Upload complete. (223ms)2008 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientCADerivations757736768/001/store/j741qmpkbkrlxk6284fjfb5vjlw8hnwh-ca-test2009 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2010 Compression: zstd2011 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2012 NarSize: 1442013 References: 2014 Deriver: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientCADerivations757736768/001/store/kdmsjrm681605chqpkyda4qbcqqhgd3m-ca-test.drv2015 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2016 client_ca_test.go:185: Checking for realisation files in S3...2017 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2018 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20192026/10/08 17:08:44 INFO Received uploads request method=POST path=/api/pending_closures2020 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket84?endpoint=http://localhost:54789®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/7db02954dc0d9130/build/TestClientCADerivations757736768/001/store'2021 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12022--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.99s)2023--- PASS: TestClientCADerivations (7.88s)20242026/10/08 17:08:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2025--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.21s)20262026/10/08 17:08:45 WARN Request failed, retrying attempt=2 backoff=209.644803ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/08 17:08:45 INFO Received uploads request method=POST path=/api/pending_closures20282026/10/08 17:08:45 WARN Request failed, retrying attempt=3 backoff=408.561939ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/08 17:08:45 INFO Received cleanup request method=DELETE path=/api/pending_closures20302026/10/08 17:08:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket90/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""20312026/10/08 17:08:45 INFO Aborted multipart uploads count=0 kept=120322026/10/08 17:08:45 INFO Received cleanup request method=DELETE path=/api/pending_closures20332026/10/08 17:08:45 INFO Aborted multipart uploads count=1 kept=02034--- PASS: TestMultipartCleanup (6.63s)20352026/10/08 17:08:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02036=== NAME TestClientIntegration2037 client_integration_test.go:323: Objects in database after GC:2038 client_integration_test.go:323: Successfully deleted all objects with GC --force2039--- PASS: TestClientIntegration (9.89s)20402026/10/08 17:08:45 WARN Request failed, retrying attempt=4 backoff=868.618553ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/08 17:08:45 INFO Received uploads request method=POST path=/api/pending_closures2042--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2043 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.54s)2044 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.56s)20452026/10/08 17:08:46 INFO Aborted multipart uploads count=0 kept=020462026/10/08 17:08:46 WARN Force mode enabled - objects will be deleted immediately without grace period20472026-10-08 17:08:46.396 UTC [75178] ERROR: canceling statement due to user request20482026-10-08 17:08:46.396 UTC [75178] STATEMENT: -- name: MarkStaleObjects :execrows2049 WITH RECURSIVE ct AS (2050 SELECT timezone('UTC', now()) AS now2051 ),2052 closure_reach AS (2053 -- Start with all closure keys2054 SELECT o.key, o.refs2055 FROM objects o2056 INNER JOIN closures c ON o.key = c.key2057 UNION2058 -- Recursively add all referenced objects2059 SELECT o.key, o.refs2060 FROM objects o2061 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2062 ),2063 reachable_objects AS (2064 SELECT DISTINCT key FROM closure_reach2065 ),2066 stale_objects AS (2067 SELECT o.key2068 FROM objects AS o, ct2069 WHERE2070 NOT EXISTS (2071 SELECT 12072 FROM reachable_objects ro2073 WHERE ro.key = o.key2074 )2075 AND NOT EXISTS (2076 SELECT 12077 FROM pending_objects AS po2078 WHERE po.key = o.key2079 )2080 AND o.deleted_at IS NULL -- Only mark fresh objects2081 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2082 FOR UPDATE2083 )2084 UPDATE objects2085 SET2086 deleted_at = ct.now,2087 first_deleted_at = COALESCE(first_deleted_at, ct.now)2088 FROM stale_objects, ct2089 WHERE objects.key = stale_objects.key2090 20912026/10/08 17:08:46 INFO Aborted multipart uploads count=0 kept=020922026/10/08 17:08:46 WARN Force mode enabled - objects will be deleted immediately without grace period20932026/10/08 17:08:46 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:54789/bucket96/?delete=\": context canceled"2094--- PASS: TestGCEndsOnShutdown (0.00s)2095 --- PASS: TestGCEndsOnShutdown/before_the_run (5.50s)2096 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.67s)2097 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.72s)20982026/10/08 17:08:46 WARN Request failed, retrying attempt=5 backoff=1.582443253s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2099--- PASS: TestPendingClosureWriteTimeout (0.00s)2100 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2101 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2102 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2103 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.29s)21042026/10/08 17:08:46 INFO Received uploads request method=POST path=/api/pending_closures21052026/10/08 17:08:46 INFO Aborted multipart uploads count=0 kept=021062026/10/08 17:08:46 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/10/08 17:08:46 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=021082026/10/08 17:08:46 INFO Vacuumed table table=pending_closures21092026/10/08 17:08:46 INFO Vacuumed table table=pending_objects21102026/10/08 17:08:46 INFO Vacuumed table table=multipart_uploads21112026/10/08 17:08:46 INFO Vacuumed table table=closures21122026/10/08 17:08:46 INFO Vacuumed table table=objects21132026/10/08 17:08:47 INFO Received uploads request method=POST path=/api/pending_closures21142026/10/08 17:08:47 INFO Aborted multipart uploads count=0 kept=021152026/10/08 17:08:47 WARN Force mode enabled - objects will be deleted immediately without grace period21162026/10/08 17:08: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=021172026/10/08 17:08:47 INFO Vacuumed table table=pending_closures21182026/10/08 17:08:47 INFO Vacuumed table table=pending_objects21192026/10/08 17:08:47 INFO Vacuumed table table=multipart_uploads21202026/10/08 17:08:47 INFO Vacuumed table table=closures21212026/10/08 17:08:47 INFO Vacuumed table table=objects2122--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2123 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.91s)2124 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.03s)21252026/10/08 17:08:47 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21262026/10/08 17:08:47 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21272026/10/08 17:08:48 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"21282026/10/08 17:08:48 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-config21292026/10/08 17:08:48 WARN Request failed, retrying attempt=2 backoff=205.611961ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21302026/10/08 17:08:48 WARN Request failed, retrying attempt=3 backoff=381.449029ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21312026/10/08 17:08:49 WARN Request failed, retrying attempt=4 backoff=794.385583ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21322026/10/08 17:08:49 WARN Request failed, retrying attempt=5 backoff=1.442579624s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21332026/10/08 17:08:50 INFO Aborted multipart uploads count=1 kept=021342026/10/08 17:08:50 INFO Received cleanup request method=DELETE path=/api/pending_closures21352026/10/08 17:08:50 INFO Aborted multipart uploads count=1 kept=02136--- PASS: TestPendingCleanupUsesOneCutoff (12.94s)2137{"timestamp":"2026-10-08T17:08:50.826209Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":5,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}21382026/10/08 17:08:51 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_closures21392026/10/08 17:08:51 WARN Request failed, retrying attempt=2 backoff=180.138288ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21402026/10/08 17:08:51 WARN Request failed, retrying attempt=3 backoff=405.255057ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21412026/10/08 17:08:51 WARN Request failed, retrying attempt=4 backoff=865.964364ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21422026/10/08 17:08:52 WARN Request failed, retrying attempt=5 backoff=1.559488173s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2143--- PASS: TestClientErrorHandling (0.02s)2144 --- PASS: TestClientErrorHandling/InvalidStorePath (6.10s)2145 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.36s)2146 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.78s)2147PASS21482026-10-08 17:08:54.568 UTC [74678] LOG: received smart shutdown request21492026-10-08 17:08:54.569 UTC [74678] LOG: background worker "logical replication launcher" (PID 74688) exited with exit code 121502026-10-08 17:08:55.729 UTC [74683] LOG: checkpoint complete: wrote 9625 buffers (58.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=11.694 s, sync=0.666 s, total=12.493 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=533347 kB, estimate=533347 kB; lsn=0/22894C00, redo lsn=0/22065B8021512026-10-08 17:08:55.730 UTC [74683] LOG: shutting down21522026-10-08 17:08:55.730 UTC [74683] LOG: checkpoint starting: shutdown immediate21532026-10-08 17:08:55.788 UTC [74683] LOG: checkpoint complete: wrote 1305 buffers (8.0%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.047 s, sync=0.010 s, total=0.059 s; sync files=534, longest=0.001 s, average=0.001 s; distance=8380 kB, estimate=480850 kB; lsn=0/22894C78, redo lsn=0/22894C7821542026-10-08 17:08:55.796 UTC [74678] LOG: database system is shut down2155Running OIDC tests...2156=== RUN TestAudienceForIssuer2157=== PAUSE TestAudienceForIssuer2158=== RUN TestGlobMatch2159=== PAUSE TestGlobMatch2160=== RUN TestValidateToken_ValidToken2161=== PAUSE TestValidateToken_ValidToken2162=== RUN TestValidateToken_WrongAudience2163=== PAUSE TestValidateToken_WrongAudience2164=== RUN TestValidateToken_Expired2165=== PAUSE TestValidateToken_Expired2166=== RUN TestValidateToken_BoundClaimsMismatch2167=== PAUSE TestValidateToken_BoundClaimsMismatch2168=== RUN TestValidateToken_BoundSubjectMismatch2169=== PAUSE TestValidateToken_BoundSubjectMismatch2170=== RUN TestValidateToken_MultipleProviders2171=== PAUSE TestValidateToken_MultipleProviders2172=== RUN TestValidateToken_NoMatchingProvider2173=== PAUSE TestValidateToken_NoMatchingProvider2174=== RUN TestValidateToken_KubernetesServiceAccount2175=== PAUSE TestValidateToken_KubernetesServiceAccount2176=== RUN TestNewValidator_KubernetesRequiresCA2177=== PAUSE TestNewValidator_KubernetesRequiresCA2178=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2179=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2180=== RUN TestPins_ReservedForMatchingRule2181=== PAUSE TestPins_ReservedForMatchingRule2182=== RUN TestPins_TopLevelShorthand2183=== PAUSE TestPins_TopLevelShorthand2184=== RUN TestPins_ConfigValidation2185=== PAUSE TestPins_ConfigValidation2186=== RUN TestScopes_LegacyProviderDefaultsToWrite2187=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2188=== RUN TestScopes_Rules2189=== PAUSE TestScopes_Rules2190=== RUN TestScopes_ConfigValidation2191=== PAUSE TestScopes_ConfigValidation2192=== CONT TestAudienceForIssuer2193--- PASS: TestAudienceForIssuer (0.00s)2194=== CONT TestValidateToken_NoMatchingProvider2195=== CONT TestPins_ConfigValidation2196=== CONT TestValidateToken_KubernetesServiceAccount2197=== CONT TestScopes_Rules2198=== CONT TestValidateToken_Expired2199=== CONT TestValidateToken_ValidToken2200=== CONT TestPins_ReservedForMatchingRule2201=== CONT TestGlobMatch2202=== RUN TestGlobMatch/foo_foo2203=== PAUSE TestGlobMatch/foo_foo2204=== RUN TestGlobMatch/foo_bar2205=== PAUSE TestGlobMatch/foo_bar2206=== RUN TestGlobMatch/*_2207=== PAUSE TestGlobMatch/*_2208=== RUN TestGlobMatch/*_anything2209=== PAUSE TestGlobMatch/*_anything2210=== RUN TestGlobMatch/foo*_foo2211=== PAUSE TestGlobMatch/foo*_foo2212=== RUN TestGlobMatch/foo*_foobar2213=== PAUSE TestGlobMatch/foo*_foobar2214=== RUN TestGlobMatch/foo*_bar2215=== PAUSE TestGlobMatch/foo*_bar2216=== RUN TestGlobMatch/*bar_bar2217=== PAUSE TestGlobMatch/*bar_bar2218=== RUN TestGlobMatch/*bar_foobar2219=== PAUSE TestGlobMatch/*bar_foobar2220=== RUN TestGlobMatch/*bar_foo2221=== PAUSE TestGlobMatch/*bar_foo2222=== RUN TestGlobMatch/foo*bar_foobar2223=== PAUSE TestGlobMatch/foo*bar_foobar2224=== RUN TestGlobMatch/foo*bar_foo123bar2225=== PAUSE TestGlobMatch/foo*bar_foo123bar2226=== RUN TestGlobMatch/foo*bar_foobarbaz2227=== PAUSE TestGlobMatch/foo*bar_foobarbaz2228=== RUN TestGlobMatch/*/*_foo/bar2229=== PAUSE TestGlobMatch/*/*_foo/bar2230=== RUN TestGlobMatch/*/*_foo2231=== PAUSE TestGlobMatch/*/*_foo2232=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2233=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2234=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02235=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02236=== RUN TestGlobMatch/refs/*/main_refs/heads/main2237=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2238=== RUN TestGlobMatch/fo?_foo2239=== PAUSE TestGlobMatch/fo?_foo2240=== RUN TestGlobMatch/fo?_fo2241=== PAUSE TestGlobMatch/fo?_fo2242=== RUN TestGlobMatch/fo?_fooo2243=== PAUSE TestGlobMatch/fo?_fooo2244=== RUN TestGlobMatch/?oo_foo2245=== PAUSE TestGlobMatch/?oo_foo2246=== RUN TestGlobMatch/?oo_boo2247=== PAUSE TestGlobMatch/?oo_boo2248=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2249=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2250=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2251=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2252=== CONT TestGlobMatch/foo_foo2253=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2254=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2255=== CONT TestGlobMatch/?oo_boo2256=== CONT TestGlobMatch/?oo_foo2257=== CONT TestGlobMatch/fo?_fooo2258=== CONT TestGlobMatch/fo?_fo2259=== CONT TestGlobMatch/fo?_foo2260=== CONT TestGlobMatch/refs/*/main_refs/heads/main2261=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02262=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2263=== CONT TestGlobMatch/*/*_foo2264=== CONT TestGlobMatch/*/*_foo/bar2265=== CONT TestGlobMatch/foo*bar_foobarbaz2266=== CONT TestGlobMatch/foo*bar_foo123bar2267=== CONT TestGlobMatch/foo*bar_foobar2268=== CONT TestGlobMatch/*bar_foo2269=== CONT TestGlobMatch/*bar_foobar2270=== CONT TestGlobMatch/*bar_bar2271=== CONT TestGlobMatch/foo*_bar2272=== CONT TestGlobMatch/foo*_foobar2273=== CONT TestGlobMatch/foo*_foo2274=== CONT TestGlobMatch/*_anything2275=== CONT TestGlobMatch/*_2276=== CONT TestGlobMatch/foo_bar2277--- PASS: TestGlobMatch (0.00s)2278 --- PASS: TestGlobMatch/foo_foo (0.00s)2279 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2280 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2281 --- PASS: TestGlobMatch/?oo_boo (0.00s)2282 --- PASS: TestGlobMatch/?oo_foo (0.00s)2283 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2284 --- PASS: TestGlobMatch/fo?_fo (0.00s)2285 --- PASS: TestGlobMatch/fo?_foo (0.00s)2286 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2287 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2288 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2289 --- PASS: TestGlobMatch/*/*_foo (0.00s)2290 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2291 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2292 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2293 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2294 --- PASS: TestGlobMatch/*bar_foo (0.00s)2295 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2296 --- PASS: TestGlobMatch/*bar_bar (0.00s)2297 --- PASS: TestGlobMatch/foo*_bar (0.00s)2298 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2299 --- PASS: TestGlobMatch/foo*_foo (0.00s)2300 --- PASS: TestGlobMatch/*_anything (0.00s)2301 --- PASS: TestGlobMatch/*_ (0.00s)2302 --- PASS: TestGlobMatch/foo_bar (0.00s)2303=== CONT TestScopes_LegacyProviderDefaultsToWrite2304--- PASS: TestPins_ConfigValidation (0.00s)2305=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2306=== CONT TestNewValidator_KubernetesRequiresCA2307=== CONT TestScopes_ConfigValidation2308=== CONT TestValidateToken_WrongAudience2309--- PASS: TestScopes_ConfigValidation (0.00s)2310=== CONT TestPins_TopLevelShorthand2311=== CONT TestValidateToken_BoundSubjectMismatch2312=== CONT TestValidateToken_BoundClaimsMismatch2313=== CONT TestValidateToken_MultipleProviders23142026/10/08 17:08:57 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323152026/10/08 17:08:57 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:552892316--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)2317--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)23182026/10/08 17:08:57 http: TLS handshake error from 127.0.0.1:55294: read tcp 127.0.0.1:55293->127.0.0.1:55294: use of closed network connection2319--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)23202026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55295/oidc2321--- PASS: TestValidateToken_WrongAudience (0.07s)23222026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55297/oidc2323--- PASS: TestValidateToken_Expired (0.08s)23242026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55301/oidc23252026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55303/oidc2326--- PASS: TestPins_TopLevelShorthand (0.10s)2327--- PASS: TestPins_ReservedForMatchingRule (0.10s)23282026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55305/oidc2329--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)23302026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55307/oidc2331--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)23322026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55309/oidc2333--- PASS: TestScopes_Rules (0.15s)23342026/10/08 17:08:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55299/oidc23352026/10/08 17:08:57 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:55311/oidc23362026/10/08 17:08:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55300/oidc2337--- PASS: TestValidateToken_NoMatchingProvider (0.15s)2338--- PASS: TestValidateToken_MultipleProviders (0.14s)23392026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55316/oidc2340--- PASS: TestValidateToken_ValidToken (0.15s)23412026/10/08 17:08:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55318/oidc2342--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)2343PASS2344Running hook tests...2345=== RUN TestSendPathsEmpty2346=== PAUSE TestSendPathsEmpty2347=== RUN TestQueueEnqueueAndFetch2348=== PAUSE TestQueueEnqueueAndFetch2349=== RUN TestQueueDeduplication2350=== PAUSE TestQueueDeduplication2351=== RUN TestQueueRemove2352=== PAUSE TestQueueRemove2353=== RUN TestQueueFetchBatchLimit2354=== PAUSE TestQueueFetchBatchLimit2355=== RUN TestQueueRetryMovesToBack2356=== PAUSE TestQueueRetryMovesToBack2357=== RUN TestQueueFetchRemoveLifecycle2358=== PAUSE TestQueueFetchRemoveLifecycle2359=== RUN TestQueueConcurrentWriters2360=== PAUSE TestQueueConcurrentWriters2361=== RUN TestQueueRemoveLargeClosure2362=== PAUSE TestQueueRemoveLargeClosure2363=== RUN TestServerClientIntegration2364--- PASS: TestServerClientIntegration (0.00s)2365=== RUN TestServerQueueError23662026/10/08 17:08:58 ERROR Failed to queue paths error="permission denied" count=12367--- PASS: TestServerQueueError (0.00s)2368=== RUN TestGetListenerSocketActivation2369 server_test.go:146: systemd socket activation does not exist on darwin2370--- SKIP: TestGetListenerSocketActivation (0.00s)2371=== RUN TestDrainIsolatesPoisonPath2372=== PAUSE TestDrainIsolatesPoisonPath2373=== RUN TestRunNotBlockedByPoisonHead2374=== PAUSE TestRunNotBlockedByPoisonHead2375=== RUN TestDrainGivesUpWhenServerDown2376=== PAUSE TestDrainGivesUpWhenServerDown2377=== RUN TestFailedPathPrunedByLaterClosure2378=== PAUSE TestFailedPathPrunedByLaterClosure2379=== RUN TestWorkerUploadsAndRemoves2380=== PAUSE TestWorkerUploadsAndRemoves2381=== RUN TestWorkerSkipsGCdPaths2382=== PAUSE TestWorkerSkipsGCdPaths2383=== RUN TestWorkerPrunesClosureDeps2384=== PAUSE TestWorkerPrunesClosureDeps2385=== RUN TestDrainTimeout2386=== PAUSE TestDrainTimeout2387=== CONT TestSendPathsEmpty2388=== CONT TestDrainIsolatesPoisonPath2389=== CONT TestFailedPathPrunedByLaterClosure2390--- PASS: TestSendPathsEmpty (0.00s)2391=== CONT TestQueueRemoveLargeClosure2392=== CONT TestQueueConcurrentWriters2393=== CONT TestQueueFetchRemoveLifecycle2394=== CONT TestQueueRetryMovesToBack2395=== CONT TestQueueFetchBatchLimit2396=== CONT TestQueueRemove2397=== CONT TestWorkerUploadsAndRemoves2398=== CONT TestQueueDeduplication2399=== CONT TestDrainTimeout2400=== CONT TestWorkerPrunesClosureDeps2401=== CONT TestWorkerSkipsGCdPaths2402=== CONT TestQueueEnqueueAndFetch2403=== CONT TestDrainGivesUpWhenServerDown2404=== CONT TestRunNotBlockedByPoisonHead2405--- PASS: TestQueueEnqueueAndFetch (0.01s)24062026/10/08 17:08:58 INFO Upload queue status pending=324072026/10/08 17:08:58 INFO Uploading batch count=124082026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=124092026/10/08 17:08:58 INFO Uploading batch count=124102026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=124112026/10/08 17:08:58 INFO Uploading batch count=424122026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=424132026/10/08 17:08:58 INFO Upload queue status pending=224142026/10/08 17:08:58 INFO Uploading batch count=224152026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainIsolatesPoisonPath2090261756/002/bbb24162026/10/08 17:08:58 INFO Uploading batch count=224172026/10/08 17:08:58 INFO Upload queue status pending=22418--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24192026/10/08 17:08:58 INFO Uploading batch count=124202026/10/08 17:08:58 INFO Uploading batch count=124212026/10/08 17:08:58 INFO Upload queue status pending=224222026/10/08 17:08:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestWorkerSkipsGCdPaths3125115929/002/nonexistent2423--- PASS: TestQueueFetchBatchLimit (0.01s)24242026/10/08 17:08:58 INFO Uploading batch count=224252026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=224262026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/a24272026/10/08 17:08:58 INFO Uploading batch count=12428--- PASS: TestQueueRetryMovesToBack (0.01s)24292026/10/08 17:08:58 INFO Uploading batch count=124302026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/b2431--- PASS: TestQueueRemove (0.01s)24322026/10/08 17:08:58 INFO Uploading batch count=124332026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=124342026/10/08 17:08:58 INFO Uploading batch count=224352026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=224362026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/c2437--- PASS: TestQueueDeduplication (0.01s)24382026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/d24392026/10/08 17:08:58 INFO Uploading batch count=124402026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=124412026/10/08 17:08:58 INFO Uploading batch count=224422026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=224432026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/e24442026/10/08 17:08:58 INFO Uploading batch count=124452026/10/08 17:08:58 ERROR Upload failed error="upload failed" count=124462026/10/08 17:08:58 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/7db02954dc0d9130/build/TestDrainGivesUpWhenServerDown2577060551/002/f24472026/10/08 17:08:58 ERROR Drain finished with paths left in queue remaining=124482026/10/08 17:08:58 ERROR Drain finished with paths left in queue remaining=102449--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2450--- PASS: TestDrainIsolatesPoisonPath (0.02s)2451--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2452--- PASS: TestWorkerUploadsAndRemoves (0.03s)2453--- PASS: TestWorkerPrunesClosureDeps (0.03s)2454--- PASS: TestWorkerSkipsGCdPaths (0.03s)2455--- PASS: TestQueueRemoveLargeClosure (0.05s)2456--- PASS: TestQueueConcurrentWriters (0.13s)24572026/10/08 17:08:58 ERROR Upload failed error="context deadline exceeded" count=224582026/10/08 17:08:58 ERROR Drain finished with paths left in queue remaining=42459--- PASS: TestDrainTimeout (0.22s)24602026/10/08 17:08:59 INFO Uploading batch count=124612026/10/08 17:08:59 INFO Uploading batch count=124622026/10/08 17:08:59 INFO Uploading batch count=124632026/10/08 17:08:59 ERROR Upload failed error="upload failed" count=124642026/10/08 17:08:59 INFO Uploading batch count=124652026/10/08 17:08:59 ERROR Upload failed error="upload failed" count=124662026/10/08 17:08:59 INFO Uploading batch count=124672026/10/08 17:08:59 ERROR Upload failed error="upload failed" count=124682026/10/08 17:08:59 INFO Uploading batch count=124692026/10/08 17:08:59 ERROR Upload failed error="upload failed" count=124702026/10/08 17:08:59 ERROR Drain finished with paths left in queue remaining=12471--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2472PASS2473Running signing tests...2474=== RUN TestExternalSigner2475=== PAUSE TestExternalSigner2476=== RUN TestExternalSignerWrongPublicKey2477=== PAUSE TestExternalSignerWrongPublicKey2478=== RUN TestExternalSignerErrors2479=== PAUSE TestExternalSignerErrors2480=== RUN TestExternalSignerRestartsAfterCrash2481=== PAUSE TestExternalSignerRestartsAfterCrash2482=== RUN TestExternalSignerProgramErrorKeepsProcess2483=== PAUSE TestExternalSignerProgramErrorKeepsProcess2484=== RUN TestExternalSignerClose2485=== PAUSE TestExternalSignerClose2486=== RUN TestExternalSignerRejectsInvalidPublicKey2487=== PAUSE TestExternalSignerRejectsInvalidPublicKey2488=== RUN TestExternalSignerCancellation2489=== PAUSE TestExternalSignerCancellation2490=== RUN TestGenerateFingerprint2491=== PAUSE TestGenerateFingerprint2492=== RUN TestParseSigningKey2493=== PAUSE TestParseSigningKey2494=== RUN TestSign2495=== PAUSE TestSign2496=== RUN TestSignBatch2497=== PAUSE TestSignBatch2498=== RUN TestNilKeyPublicKey2499=== PAUSE TestNilKeyPublicKey2500=== RUN TestSignErrors2501=== PAUSE TestSignErrors2502=== CONT TestExternalSigner2503=== CONT TestExternalSignerCancellation2504=== CONT TestSignBatch2505=== CONT TestParseSigningKey2506=== CONT TestSignErrors2507=== CONT TestNilKeyPublicKey2508--- PASS: TestNilKeyPublicKey (0.00s)2509=== CONT TestExternalSignerRejectsInvalidPublicKey2510=== RUN TestParseSigningKey/valid_32-byte_key2511=== RUN TestExternalSignerRejectsInvalidPublicKey/#002512=== CONT TestExternalSignerClose2513=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002514=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2515=== CONT TestExternalSignerProgramErrorKeepsProcess2516=== CONT TestSign2517=== CONT TestExternalSignerErrors2518=== RUN TestExternalSignerErrors/wrong_id2519=== PAUSE TestExternalSignerErrors/wrong_id2520=== RUN TestExternalSignerErrors/exit_on_request2521=== PAUSE TestExternalSignerErrors/exit_on_request2522=== RUN TestExternalSignerErrors/missing_signatures2523=== PAUSE TestExternalSignerErrors/missing_signatures2524=== RUN TestExternalSignerErrors/wrong_signatures_shape2525=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2526=== RUN TestExternalSignerErrors/unrequested_key2527=== PAUSE TestExternalSignerErrors/unrequested_key2528=== RUN TestExternalSignerErrors/missing_signature_name2529=== PAUSE TestExternalSignerErrors/missing_signature_name2530=== RUN TestExternalSignerErrors/wrong_signature_name2531=== PAUSE TestExternalSignerErrors/wrong_signature_name2532=== RUN TestExternalSignerErrors/invalid_signature_base642533=== PAUSE TestExternalSignerErrors/invalid_signature_base642534=== RUN TestExternalSignerErrors/exit_at_startup2535=== PAUSE TestExternalSignerErrors/exit_at_startup2536=== RUN TestExternalSignerErrors/invalid_JSON2537=== PAUSE TestExternalSignerErrors/invalid_JSON2538=== RUN TestExternalSignerErrors/too_few_signatures2539=== PAUSE TestExternalSignerErrors/too_few_signatures2540=== RUN TestExternalSignerErrors/wrong_shape2541=== PAUSE TestExternalSignerErrors/wrong_shape2542=== RUN TestExternalSignerErrors/null2543=== CONT TestExternalSignerRestartsAfterCrash2544=== PAUSE TestExternalSignerErrors/null2545=== RUN TestExternalSignerErrors/null_signatures2546=== PAUSE TestExternalSignerErrors/null_signatures2547=== RUN TestExternalSignerErrors/wrong_signature_length2548=== PAUSE TestExternalSignerErrors/wrong_signature_length2549=== RUN TestExternalSignerErrors/program_error2550=== PAUSE TestExternalSignerErrors/program_error2551=== CONT TestExternalSignerErrors/wrong_id2552=== CONT TestExternalSignerWrongPublicKey2553=== CONT TestExternalSignerErrors/exit_at_startup2554=== CONT TestExternalSignerErrors/null2555=== CONT TestExternalSignerErrors/too_few_signatures2556=== CONT TestExternalSignerErrors/invalid_signature_base642557=== CONT TestExternalSignerErrors/invalid_JSON2558=== CONT TestGenerateFingerprint2559=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2560=== PAUSE TestParseSigningKey/valid_32-byte_key2561=== CONT TestExternalSignerErrors/unrequested_key2562=== CONT TestExternalSignerErrors/wrong_signature_name2563=== CONT TestExternalSignerErrors/missing_signature_name2564=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2565=== RUN TestGenerateFingerprint/basic_with_references2566=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2567=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2568=== RUN TestParseSigningKey/no_colon2569=== PAUSE TestParseSigningKey/no_colon2570=== RUN TestParseSigningKey/empty_name2571=== PAUSE TestParseSigningKey/empty_name2572=== RUN TestParseSigningKey/invalid_base642573=== PAUSE TestParseSigningKey/invalid_base642574=== RUN TestParseSigningKey/wrong_length2575=== PAUSE TestParseSigningKey/wrong_length2576=== CONT TestExternalSignerErrors/program_error2577=== CONT TestExternalSignerErrors/wrong_signatures_shape2578=== CONT TestExternalSignerErrors/missing_signatures2579=== CONT TestExternalSignerErrors/wrong_signature_length2580=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2581=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2582=== PAUSE TestGenerateFingerprint/basic_with_references2583=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2584=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2585=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2586=== CONT TestExternalSignerErrors/exit_on_request2587=== RUN TestGenerateFingerprint/no_references2588=== RUN TestSignErrors/nil_key2589=== PAUSE TestSignErrors/nil_key2590=== RUN TestSignErrors/nil_narinfo2591=== PAUSE TestSignErrors/nil_narinfo2592=== RUN TestSignErrors/invalid_narinfo2593=== PAUSE TestSignErrors/invalid_narinfo2594=== RUN TestSignErrors/canceled2595=== PAUSE TestSignErrors/canceled2596=== PAUSE TestGenerateFingerprint/no_references2597=== CONT TestExternalSignerErrors/null_signatures2598=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2599=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2600=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2601=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2602=== RUN TestGenerateFingerprint/invalid_nar_hash_length2603=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2604=== RUN TestGenerateFingerprint/invalid_store_path_prefix2605=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2606=== RUN TestGenerateFingerprint/invalid_reference_prefix2607=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2608=== CONT TestExternalSignerErrors/wrong_shape2609=== CONT TestParseSigningKey/valid_32-byte_key2610=== CONT TestParseSigningKey/invalid_base642611=== CONT TestParseSigningKey/wrong_length2612=== CONT TestParseSigningKey/empty_name2613=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2614=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2615=== CONT TestExternalSignerRejectsInvalidPublicKey/#002616=== CONT TestParseSigningKey/no_colon2617--- PASS: TestSign (0.00s)2618--- PASS: TestSignBatch (0.01s)2619=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2620=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2621=== CONT TestSignErrors/nil_key2622=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2623--- PASS: TestParseSigningKey (0.00s)2624 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2625 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2626 --- PASS: TestParseSigningKey/wrong_length (0.00s)2627 --- PASS: TestParseSigningKey/empty_name (0.00s)2628 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2629 --- PASS: TestParseSigningKey/no_colon (0.00s)2630=== CONT TestSignErrors/invalid_narinfo2631=== CONT TestSignErrors/canceled2632=== CONT TestSignErrors/nil_narinfo2633=== CONT TestGenerateFingerprint/basic_with_references2634--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2635 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2636 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2637 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2638 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2639 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2640=== CONT TestGenerateFingerprint/invalid_nar_hash_length2641--- PASS: TestSignErrors (0.01s)2642 --- PASS: TestSignErrors/nil_key (0.00s)2643 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2644 --- PASS: TestSignErrors/canceled (0.00s)2645 --- PASS: TestSignErrors/nil_narinfo (0.00s)2646=== CONT TestGenerateFingerprint/invalid_reference_prefix2647=== CONT TestGenerateFingerprint/invalid_store_path_prefix2648=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2649=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2650=== CONT TestGenerateFingerprint/no_references2651--- PASS: TestGenerateFingerprint (0.00s)2652 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2653 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2654 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2655 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2656 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2657 --- PASS: TestGenerateFingerprint/no_references (0.00s)2658 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2659--- PASS: TestExternalSignerClose (0.22s)2660--- PASS: TestExternalSignerCancellation (1.14s)2661--- PASS: TestExternalSignerRestartsAfterCrash (1.51s)2662/private/var/tb/3/scratch/7db02954dc0d9130/build/TestExternalSignerRestartsAfterCrash975942510/001/sign program: line 7: /private/var/tb/3/scratch/7db02954dc0d9130/build/TestExternalSignerRestartsAfterCrash975942510/001/sign program.starts: No such file or directory2663--- PASS: TestExternalSigner (1.68s)2664--- PASS: TestExternalSignerWrongPublicKey (2.03s)2665--- PASS: TestExternalSignerProgramErrorKeepsProcess (2.21s)2666--- PASS: TestExternalSignerErrors (0.00s)2667 --- PASS: TestExternalSignerErrors/missing_signature_name (0.39s)2668 --- PASS: TestExternalSignerErrors/exit_at_startup (0.58s)2669 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.76s)2670 --- PASS: TestExternalSignerErrors/null (0.94s)2671 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.30s)2672 --- PASS: TestExternalSignerErrors/program_error (1.85s)2673 --- PASS: TestExternalSignerErrors/invalid_JSON (2.40s)2674 --- PASS: TestExternalSignerErrors/too_few_signatures (2.57s)2675 --- PASS: TestExternalSignerErrors/exit_on_request (2.75s)2676 --- PASS: TestExternalSignerErrors/missing_signatures (2.94s)2677 --- PASS: TestExternalSignerErrors/wrong_id (3.13s)2678 --- PASS: TestExternalSignerErrors/null_signatures (3.31s)2679 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.50s)2680 --- PASS: TestExternalSignerErrors/wrong_signature_length (3.68s)2681 --- PASS: TestExternalSignerErrors/wrong_shape (3.86s)2682 --- PASS: TestExternalSignerErrors/unrequested_key (4.05s)2683PASS2684Running OpenBao signer tests...2685=== RUN TestSign2686=== PAUSE TestSign2687=== RUN TestSignErrors2688=== PAUSE TestSignErrors2689=== RUN TestServe2690=== PAUSE TestServe2691=== RUN TestServeRejectsGarbage2692=== PAUSE TestServeRejectsGarbage2693=== CONT TestSign2694=== CONT TestServe2695=== CONT TestSignErrors2696=== RUN TestSignErrors/http_error2697=== CONT TestServeRejectsGarbage2698=== PAUSE TestSignErrors/http_error2699--- PASS: TestServeRejectsGarbage (0.00s)2700=== RUN TestSignErrors/invalid_json2701=== PAUSE TestSignErrors/invalid_json2702=== RUN TestSignErrors/no_prefix2703=== PAUSE TestSignErrors/no_prefix2704=== RUN TestSignErrors/invalid_base642705=== PAUSE TestSignErrors/invalid_base642706=== CONT TestSignErrors/http_error2707=== CONT TestSignErrors/invalid_json2708=== CONT TestSignErrors/no_prefix2709--- PASS: TestServe (0.00s)2710=== CONT TestSignErrors/invalid_base642711--- PASS: TestSign (0.00s)2712--- PASS: TestSignErrors (0.00s)2713 --- PASS: TestSignErrors/no_prefix (0.00s)2714 --- PASS: TestSignErrors/invalid_base64 (0.00s)2715 --- PASS: TestSignErrors/http_error (0.00s)2716 --- PASS: TestSignErrors/invalid_json (0.00s)2717PASS