niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #399
· 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.10s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.01s)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 TestScriptTokenNoExpiryRerunsEveryCall107=== CONT TestStaticToken108--- PASS: TestStaticToken (0.00s)109=== CONT TestRetryTimeoutOutlastsMaxRetries110=== CONT TestScriptTokenCachesUntilRefresh111=== CONT TestScriptTokenEmptyCommand112--- PASS: TestScriptTokenEmptyCommand (0.00s)113=== CONT TestDoWithRetry_BodyReplayedViaGetBody114=== CONT TestScriptTokenScriptFails115=== CONT TestScriptTokenBadJSON116=== CONT TestScriptTokenEmptyToken117=== CONT TestRateLimiterFeedback118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== CONT TestSetClientTLSErrors120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121=== CONT TestSetClientTLS1222026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:528481232026/10/08 12:58:57 WARN Rate limiter enabled after throttle name=server-test rate=51242026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:52851125=== CONT TestStreamPushStopsWhenCanceled126=== CONT TestClientSignaturesByStorePath127=== CONT TestFileTokenMissing128=== CONT TestStreamPushReportsSkippedPaths129=== CONT TestFileTokenEmpty130=== CONT TestStreamPushRequestLine131=== CONT TestStreamPushGivesUpOnDeadServer1322026/10/08 12:58:57 WARN Rate limiter backed off name=server-test rate=51332026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:528511342026/10/08 12:58:57 ERROR Upload failed error=boom count=1135=== CONT TestStreamPushIsolatesFailures1362026/10/08 12:58:57 ERROR Upload failed error="connection refused" count=20137=== CONT TestStreamPushBatchesUnderLoad1382026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:528481392026/10/08 12:58:57 ERROR Upload failed error="bad path" count=3140=== CONT TestStreamPushReportsEveryPath141=== CONT TestShellSplitErrors142=== CONT TestShellSplit143=== RUN TestSetClientTLSErrors/missing_cert_file144=== PAUSE TestSetClientTLSErrors/missing_cert_file1452026/10/08 12:58:57 ERROR Server seems unavailable, giving up on batch untried=171462026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:52848147=== CONT TestDumpPathSingleFile148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149--- PASS: TestDoServerRequestAttachesToken (0.00s)150=== CONT TestResolveStorePath151=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess152=== CONT TestStreamPushReportsSignatures153=== CONT TestFilterOversizedClosures154=== CONT TestDumpPathMatchesNix155=== CONT TestPathInfoCACompatibility156=== CONT TestParsePathInfoJSONMultiplePaths157=== CONT TestParsePathInfoJSON158=== CONT TestPathInfoHashCompatibility159=== CONT TestGetStorePathHash160=== CONT TestConvertHashToNix32161=== RUN TestConvertHashToNix32/SRI_format_to_Nix32162=== RUN TestGetStorePathHash/valid_store_path163=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== RUN TestParsePathInfoJSON/Nix_format165=== RUN TestPathInfoCACompatibility/null_ca_field166=== PAUSE TestPathInfoCACompatibility/null_ca_field167=== RUN TestPathInfoCACompatibility/old_string_format_-_text168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text169=== PAUSE TestParsePathInfoJSON/Nix_format170=== RUN TestSetClientTLSErrors/missing_key_file171=== PAUSE TestSetClientTLSErrors/missing_key_file172=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive173=== RUN TestFilterOversizedClosures/no_limit_keeps_everything174=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== RUN TestConvertHashToNix32/already_Nix32_format177=== PAUSE TestConvertHashToNix32/already_Nix32_format178=== CONT TestEncodeNixBase32179=== CONT TestEncodeNixBase32WithRealHash180=== CONT TestDumpPathWriterError1812026/10/08 12:58:57 ERROR Upload failed error=boom count=1182=== CONT TestFileTokenReadsAndCaches183=== RUN TestRateLimiterFeedback/503_enables_limiter184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== RUN TestConvertHashToNix32/invalid_format186=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything187=== PAUSE TestGetStorePathHash/valid_store_path188=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189=== RUN TestParsePathInfoJSON/Lix_format190--- PASS: TestScriptTokenScriptFails (0.00s)1912026/10/08 12:58:57 WARN Rate limiter enabled after throttle name=server-test rate=5192--- PASS: TestStreamPushStopsWhenCanceled (0.00s)193=== RUN TestSetClientTLSErrors/missing_ca_file194=== PAUSE TestRateLimiterFeedback/503_enables_limiter195--- PASS: TestClientSignaturesByStorePath (0.00s)196--- PASS: TestFileTokenReadsAndCaches (0.00s)197--- PASS: TestStreamPushReportsSkippedPaths (0.00s)198--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)199--- PASS: TestFileTokenMissing (0.01s)200=== CONT TestUploadMultipart_SupersededByPeer201=== PAUSE TestSetClientTLSErrors/missing_ca_file202=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths203=== PAUSE TestParsePathInfoJSON/Lix_format204--- PASS: TestStreamPushIsolatesFailures (0.00s)205--- PASS: TestShellSplitErrors (0.00s)206--- PASS: TestShellSplit (0.00s)207--- PASS: TestStreamPushReportsEveryPath (0.00s)208--- PASS: TestStreamPushRequestLine (0.01s)209--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)210--- PASS: TestFileTokenEmpty (0.02s)211--- PASS: TestEncodeNixBase32WithRealHash (0.00s)212--- PASS: TestStreamPushReportsSignatures (0.00s)213=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter214=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter215=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter216=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter217=== RUN TestGetStorePathHash/basename_without_hyphen_should_error218=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error219=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error220=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error221=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error222=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error223=== RUN TestPathInfoCACompatibility/new_structured_format_-_text224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text225=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method226=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method227=== RUN TestEncodeNixBase32/test_string_hash228=== PAUSE TestEncodeNixBase32/test_string_hash229--- PASS: TestResolveStorePath (0.00s)230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== CONT TestPartSizeForNAR232=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== RUN TestUploadMultipart_SupersededByPeer/exists234=== RUN TestFilterOversizedClosures/all_closures_skipped235=== RUN TestSetClientTLSErrors/invalid_ca_file236=== RUN TestEncodeNixBase32/empty_input237=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths238=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths239=== PAUSE TestUploadMultipart_SupersededByPeer/exists240=== RUN TestUploadMultipart_SupersededByPeer/missing241=== PAUSE TestUploadMultipart_SupersededByPeer/missing242=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica243=== PAUSE TestConvertHashToNix32/invalid_format2442026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:52848245=== PAUSE TestFilterOversizedClosures/all_closures_skipped246=== CONT TestPathInfoCACompatibility/null_ca_field247=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method248=== RUN TestParsePathInfoJSON/empty_input249=== PAUSE TestParsePathInfoJSON/empty_input250=== RUN TestParsePathInfoJSON/whitespace_only251=== PAUSE TestParsePathInfoJSON/whitespace_only252=== RUN TestParsePathInfoJSON/invalid_JSON253=== PAUSE TestParsePathInfoJSON/invalid_JSON254=== CONT TestPathInfoCACompatibility/new_structured_format_-_text255=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error256=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error257=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter258=== PAUSE TestEncodeNixBase32/empty_input259=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon260=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun261=== CONT TestUploadMultipart_PartsInParallel262=== PAUSE TestSetClientTLSErrors/invalid_ca_file263=== CONT TestCaseHackSuffix264=== RUN TestPartSizeForNAR/zero_stays_at_minimum265=== CONT TestRateLimiterFeedback/429_enables_limiter266=== CONT TestRegisterUploadedObjectReusesConnections267=== RUN TestSetClientTLS/rejects_connection_without_client_cert268--- PASS: TestScriptTokenBadJSON (0.04s)269=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive270--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)271=== CONT TestGetStorePathHash/valid_store_path272=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths273=== CONT TestUploadMultipart_SupersededByPeer/exists274=== CONT TestPathInfoCACompatibility/old_string_format_-_text275--- PASS: TestPathInfoCACompatibility (0.00s)276 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)277 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)278 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)279 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)280 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)281=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon282=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI283=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI284=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512285=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512286=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths287--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290=== CONT TestGetStorePathHash/basename_without_hyphen_should_error291--- PASS: TestGetStorePathHash (0.00s)292 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)293 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)294 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)295 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)296=== CONT TestConvertHashToNix32/invalid_format2972026/10/08 12:58:57 INFO Garbage collection started2982026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:528482992026/10/08 12:58:57 WARN Rate limiter enabled after throttle name=server-test rate=5300=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum301=== RUN TestPartSizeForNAR/small_stays_at_minimum302=== PAUSE TestPartSizeForNAR/small_stays_at_minimum303=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum304=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum305=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts306=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts3072026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:528643082026/10/08 12:58:57 INFO Garbage collection started3092026/10/08 12:58:57 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=0310=== RUN TestPartSizeForNAR/1_TiB311=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert312=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter313=== CONT TestRateLimiterFeedback/503_enables_limiter314=== PAUSE TestPartSizeForNAR/1_TiB315=== RUN TestPartSizeForNAR/5_TiB_S3_max_object316=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object317=== RUN TestPartSizeForNAR/capped_at_5_GiB318=== PAUSE TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestUploadMultipart_SupersededByPeer/missing320=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321=== CONT TestConvertHashToNix32/SRI_format_to_Nix32322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything323=== CONT TestFilterOversizedClosures/all_closures_skipped324=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA325=== CONT TestConvertHashToNix32/already_Nix32_format326--- PASS: TestScriptTokenEmptyToken (0.06s)327=== CONT TestParsePathInfoJSON/Nix_format328=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA329=== RUN TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestSetClientTLS/preserves_debug_logging_transport331=== CONT TestParsePathInfoJSON/invalid_JSON332=== CONT TestSetClientTLSErrors/missing_cert_file333=== CONT TestParsePathInfoJSON/Lix_format334--- PASS: TestConvertHashToNix32 (0.01s)335 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)336 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)337 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)338=== CONT TestEncodeNixBase32/test_string_hash339=== CONT TestParsePathInfoJSON/whitespace_only340=== CONT TestSetClientTLSErrors/missing_key_file341=== CONT TestSetClientTLSErrors/missing_ca_file342=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)343=== CONT TestEncodeNixBase32/empty_input344--- PASS: TestEncodeNixBase32 (0.01s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3472026/10/08 12:58:57 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=20003482026/10/08 12:58:57 WARN Rate limiter backed off name=server-test rate=53492026/10/08 12:58:57 WARN Garbage collection finished on another replica. Its statistics are not available here3502026/10/08 12:58:57 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=503512026/10/08 12:58:57 WARN Rate limiter enabled after throttle name=server-test rate=53522026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:529393532026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:52848354=== CONT TestSetClientTLSErrors/invalid_ca_file3552026/10/08 12:58:57 WARN Rate limiter backed off name=server-test rate=53562026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:52848357=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA358=== CONT TestParsePathInfoJSON/empty_input359=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon360=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363=== CONT TestPartSizeForNAR/1_TiB364=== CONT TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/small_stays_at_minimum368=== CONT TestPartSizeForNAR/5_TiB_S3_max_object369--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)370 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)371 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)372--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)373--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)374--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)375--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)376--- PASS: TestRateLimiterFeedback (0.04s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)378 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)379 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)380 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)381=== CONT TestSetClientTLS/rejects_connection_without_client_cert382=== CONT TestSetClientTLS/preserves_debug_logging_transport383--- PASS: TestFilterOversizedClosures (0.01s)384 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)385 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.01s)386 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.01s)387--- PASS: TestPathInfoHashCompatibility (0.01s)388 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)389 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)390 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)391 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)392--- PASS: TestPartSizeForNAR (0.02s)393 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)394 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)395 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)396 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)397 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)398 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)399 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)400--- PASS: TestParsePathInfoJSON (0.01s)401 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)402 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)403 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)404 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)405 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)406--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)4072026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:52848408--- PASS: TestSetClientTLSErrors (0.05s)409 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)410 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)411 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)412 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)4132026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:528484142026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:528484152026/10/08 12:58:57 http: TLS handshake error from 127.0.0.1:52943: remote error: tls: bad certificate4162026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:52848417--- PASS: TestDumpPathSingleFile (0.05s)4182026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:528484192026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:52848420--- PASS: TestSetClientTLS (0.05s)421 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)422 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)423 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4242026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:528484252026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:52848426--- PASS: TestCaseHackSuffix (0.05s)4272026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:528484282026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:528484292026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:528484302026/10/08 12:58:57 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:52848431--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.12s)432--- PASS: TestStreamPushBatchesUnderLoad (0.10s)433--- PASS: TestDumpPathWriterError (0.25s)434--- PASS: TestDumpPathMatchesNix (0.25s)435--- PASS: TestUploadMultipart_PartsInParallel (0.61s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "_tribuchetbld8".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/8/scratch/f058402f878f26dd/build/postgres1865263893/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/8/scratch/f058402f878f26dd/build/postgres1865263893/data -l logfile start465466/private/var/tb/8/scratch/f058402f878f26dd/build/postgres1865263893:5432 - no response4672026-10-08 12:59:06.478 UTC [45012] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4682026-10-08 12:59:06.494 UTC [45012] LOG: listening on Unix socket "/private/var/tb/8/scratch/f058402f878f26dd/build/postgres1865263893/.s.PGSQL.5432"4692026-10-08 12:59:06.505 UTC [45019] LOG: database system was shut down at 2026-10-08 12:59:06 UTC4702026-10-08 12:59:06.515 UTC [45012] LOG: database system is ready to accept connections471/private/var/tb/8/scratch/f058402f878f26dd/build/postgres1865263893:5432 - accepting connections472{"timestamp":"2026-10-08T12:59:06.714209Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"20761211-f1a8-49a8-81a2-c35256d7b0d8","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(4)"}473{"timestamp":"2026-10-08T12:59:06.819129Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fdee4737-b068-437b-a700-c2f9e335724d","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(3)"}474{"timestamp":"2026-10-08T12:59:06.922951Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d46c6db6-13a9-41eb-93df-1f9d4bcfbcdf","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(4)"}475{"timestamp":"2026-10-08T12:59:07.026921Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"86f5ebe6-383f-4c7a-9531-ce9a0532f00a","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(6)"}476=== RUN TestService_AuthMiddleware477=== PAUSE TestService_AuthMiddleware478=== RUN TestService_AuthMiddleware_MTLSProxyHeader479=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader480=== RUN TestService_AuthMiddleware_MTLSBoundSubjects481=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects482=== RUN TestService_ReadAuthMiddleware483=== PAUSE TestService_ReadAuthMiddleware484=== RUN TestService_AuthMiddleware_OIDC485=== PAUSE TestService_AuthMiddleware_OIDC486=== RUN TestService_RequireScope_OIDC487=== PAUSE TestService_RequireScope_OIDC488=== RUN TestService_ReadScope_PublicByDefault489=== PAUSE TestService_ReadScope_PublicByDefault490=== RUN TestCacheConfigHandler491=== PAUSE TestCacheConfigHandler492=== RUN TestCacheStatsHandler493=== PAUSE TestCacheStatsHandler494=== RUN TestClientCADerivations495=== PAUSE TestClientCADerivations496=== RUN TestClientErrorHandling497=== PAUSE TestClientErrorHandling498=== RUN TestClientIntegration499=== PAUSE TestClientIntegration500=== RUN TestClientMultipleUploads501=== PAUSE TestClientMultipleUploads502=== RUN TestClientWithDependencies503=== PAUSE TestClientWithDependencies504=== RUN TestClientSharedPathCommittedMidPush505=== PAUSE TestClientSharedPathCommittedMidPush506=== RUN TestPinProtectsFromGC507=== PAUSE TestPinProtectsFromGC508=== RUN TestClientPushesUseOnePush509=== PAUSE TestClientPushesUseOnePush510=== RUN TestClientFallsBackToClosures511=== PAUSE TestClientFallsBackToClosures512=== RUN TestDeleteClosuresRacingPins513=== PAUSE TestDeleteClosuresRacingPins514=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock515=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock516=== RUN TestResolveDBConnectionString517=== PAUSE TestResolveDBConnectionString518=== RUN TestConnectWaitsForAPeerMigration519=== PAUSE TestConnectWaitsForAPeerMigration520=== RUN TestLeadElectsOneAndHandsOver521=== PAUSE TestLeadElectsOneAndHandsOver522=== RUN TestLeadIncumbentWinsAfterRestart5232026/10/08 12:59:10 INFO lead: acquired remote=192.0.2.1:12345242026/10/08 12:59:11 INFO lead: released remote=192.0.2.1:12345252026/10/08 12:59:11 INFO lead: acquired remote=192.0.2.1:12345262026/10/08 12:59:12 INFO lead: released remote=192.0.2.1:1234527--- PASS: TestLeadIncumbentWinsAfterRestart (5.13s)528=== RUN TestLeadIncumbentAnnouncesAtOnce529=== PAUSE TestLeadIncumbentAnnouncesAtOnce530=== RUN TestLeadEndsOnShutdown531=== PAUSE TestLeadEndsOnShutdown532=== RUN TestLeadEndsWhenItsConnectionHangs5332026/10/08 12:59:14 INFO lead: acquired remote=192.0.2.1:12345342026-10-08 12:59:16.039 UTC [45114] FATAL: terminating connection due to administrator command5352026/10/08 12:59:16 INFO lead: acquired remote=192.0.2.1:12345362026/10/08 12:59:17 WARN lead: lock connection lost error="timeout: context deadline exceeded"5372026/10/08 12:59:17 INFO lead: released remote=192.0.2.1:12345382026/10/08 12:59:17 INFO lead: released remote=192.0.2.1:1234539--- PASS: TestLeadEndsWhenItsConnectionHangs (5.15s)540=== RUN TestGCAdvisoryLockBlocksConcurrentRun541=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun542=== RUN TestGCBugBareHashReferences543=== PAUSE TestGCBugBareHashReferences544=== RUN TestGCMetrics545=== PAUSE TestGCMetrics546=== RUN TestPushDedupSurvivesConcurrentGC547=== PAUSE TestPushDedupSurvivesConcurrentGC548=== RUN TestDeduplicatedObjectsRecordedAsPending549=== PAUSE TestDeduplicatedObjectsRecordedAsPending550=== RUN TestGCSweepSkipsPendingObjects551=== PAUSE TestGCSweepSkipsPendingObjects552=== RUN TestTombstonedObjectOfferedWithoutWaiting553=== PAUSE TestTombstonedObjectOfferedWithoutWaiting554=== RUN TestGCSweepDeliversEachKeyOnce555=== PAUSE TestGCSweepDeliversEachKeyOnce556=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection557=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection558=== RUN TestForceGCDuringPushOffersSweptObject559=== PAUSE TestForceGCDuringPushOffersSweptObject560=== RUN TestFailedS3DeleteKeepsTombstone561=== PAUSE TestFailedS3DeleteKeepsTombstone562=== RUN TestSweepSkipsRowsLockedByPush563=== PAUSE TestSweepSkipsRowsLockedByPush564=== RUN TestRegisterCompletedObjectNeedsPendingRow565=== PAUSE TestRegisterCompletedObjectNeedsPendingRow566=== RUN TestGetExistingObjectsLocksRows567=== PAUSE TestGetExistingObjectsLocksRows568=== RUN TestSweepRechecksPendingAfterLocking569=== PAUSE TestSweepRechecksPendingAfterLocking570=== RUN TestPushWaitsForSweepHoldingRow571=== PAUSE TestPushWaitsForSweepHoldingRow572=== RUN TestCommitRacingPendingCleanupKeepsObjects573=== PAUSE TestCommitRacingPendingCleanupKeepsObjects574=== RUN TestGCEndsOnShutdown575=== PAUSE TestGCEndsOnShutdown576=== RUN TestGCTaskStore_StartNew577=== PAUSE TestGCTaskStore_StartNew578=== RUN TestGCTaskStore_DeduplicateSameParams579=== PAUSE TestGCTaskStore_DeduplicateSameParams580=== RUN TestGCTaskStore_ConflictDifferentParams581=== PAUSE TestGCTaskStore_ConflictDifferentParams582=== RUN TestGCTaskStore_GetEmpty583=== PAUSE TestGCTaskStore_GetEmpty584=== RUN TestGCTaskStore_GetReturnsLatest585=== PAUSE TestGCTaskStore_GetReturnsLatest586=== RUN TestGCTaskStore_CompletedAllowsNewTask587=== PAUSE TestGCTaskStore_CompletedAllowsNewTask588=== RUN TestGCTaskStore_PhaseUpdates589=== PAUSE TestGCTaskStore_PhaseUpdates590=== RUN TestGCTaskStore_Fail591=== PAUSE TestGCTaskStore_Fail592=== RUN TestGracefulShutdownDrainsInflight593=== PAUSE TestGracefulShutdownDrainsInflight594=== RUN TestService_healthCheckHandler595=== PAUSE TestService_healthCheckHandler596=== RUN TestService_readinessHandler597=== PAUSE TestService_readinessHandler598=== RUN TestGenerateLandingPage599=== PAUSE TestGenerateLandingPage600=== RUN TestCacheConfigHandlerMaxNarSize601=== PAUSE TestCacheConfigHandlerMaxNarSize602=== RUN TestCreatePendingClosureRejectsOversizedNAR603=== PAUSE TestCreatePendingClosureRejectsOversizedNAR604=== RUN TestNARDeduplicationMetadataUploadBug605=== PAUSE TestNARDeduplicationMetadataUploadBug606=== RUN TestMetricsInventory607=== PAUSE TestMetricsInventory608=== RUN TestMetricsCommit609=== PAUSE TestMetricsCommit610=== RUN TestService_NativeMTLS611=== PAUSE TestService_NativeMTLS612=== RUN TestServerTLSConfig613=== PAUSE TestServerTLSConfig614=== RUN TestMultipartCleanup615=== PAUSE TestMultipartCleanup616=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded617=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded618=== RUN TestPendingCleanupUsesOneCutoff619=== PAUSE TestPendingCleanupUsesOneCutoff620=== RUN TestObjectStatsTrigger621=== PAUSE TestObjectStatsTrigger622=== RUN TestObjectStatsLargeCommit623=== PAUSE TestObjectStatsLargeCommit624=== RUN TestOrphanedObjectsGC625=== PAUSE TestOrphanedObjectsGC626=== RUN TestOrphanedObjectsGCStressTest627=== PAUSE TestOrphanedObjectsGCStressTest628=== RUN TestCreatePin_ReservedPins629=== PAUSE TestCreatePin_ReservedPins630=== RUN TestPresentReportsOnlyClosureRoots631=== PAUSE TestPresentReportsOnlyClosureRoots632=== RUN TestPresentRefreshesOnlyStaleClosures633=== PAUSE TestPresentRefreshesOnlyStaleClosures634=== RUN TestPresentNotReportedWhileGCDeletesClosure635=== PAUSE TestPresentNotReportedWhileGCDeletesClosure636=== RUN TestParseSingleRange637=== PAUSE TestParseSingleRange638=== RUN TestProxyHeadersOnlyTrustedOnSocket6392026/10/08 12:59:17 INFO Starting HTTP server address=127.0.0.1:532556402026/10/08 12:59:17 INFO Starting HTTP server address=proxy.sock6412026/10/08 12:59:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6422026/10/08 12:59:17 INFO Shutdown signal received, draining in-flight requests timeout=10s643--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.33s)644=== RUN TestIsValidCachePath645=== PAUSE TestIsValidCachePath646=== RUN TestReadProxyNarinfo647=== PAUSE TestReadProxyNarinfo648=== RUN TestReadProxyNarinfoAlreadyDecompressed649=== PAUSE TestReadProxyNarinfoAlreadyDecompressed650=== RUN TestReadProxyContentNegotiation651=== PAUSE TestReadProxyContentNegotiation652=== RUN TestReadProxyNarStreaming653=== PAUSE TestReadProxyNarStreaming654=== RUN TestReadProxy404655=== PAUSE TestReadProxy404656=== RUN TestReadProxyInvalidPath657=== PAUSE TestReadProxyInvalidPath658=== RUN TestReadProxyHead659=== PAUSE TestReadProxyHead660=== RUN TestReadProxyOutlastsServerWriteTimeout661=== PAUSE TestReadProxyOutlastsServerWriteTimeout662=== RUN TestReadProxyConditionalGet663=== PAUSE TestReadProxyConditionalGet664=== RUN TestReadProxyRootRedirectsToIndexHTML665=== PAUSE TestReadProxyRootRedirectsToIndexHTML666=== RUN TestReadProxyDisabled667=== PAUSE TestReadProxyDisabled668=== RUN TestReadRedirectNar669=== PAUSE TestReadRedirectNar670=== RUN TestReadRedirectKeepsNarinfoProxied671=== PAUSE TestReadRedirectKeepsNarinfoProxied672=== RUN TestReadProxyRangeRequest673=== PAUSE TestReadProxyRangeRequest674=== RUN TestReadRedirectUsesPublicS3URL675=== PAUSE TestReadRedirectUsesPublicS3URL676=== RUN TestPush_OverlappingRootsStoreOneRowPerKey677=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey678=== RUN TestPush_CompleteCommitsEveryRoot679=== PAUSE TestPush_CompleteCommitsEveryRoot680=== RUN TestPush_RepeatedRootCommitsOnce681=== PAUSE TestPush_RepeatedRootCommitsOnce682=== RUN TestPush_CompleteWaitsForCleanupOfThePush683=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush684=== RUN TestPush_RootsAreLockedInByteOrder685=== PAUSE TestPush_RootsAreLockedInByteOrder686=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit687=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit688=== RUN TestPush_RejectsBadRequests689=== PAUSE TestPush_RejectsBadRequests690=== RUN TestPush_SignsNarinfosOfItsPendingObjects691=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects692=== RUN TestRedundantMultipartUpload693=== PAUSE TestRedundantMultipartUpload694=== RUN TestCompleteMultipartUpload_ErrorButObjectExists695=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists696=== RUN TestCompletedNarNotReofferedAcrossClosures697=== PAUSE TestCompletedNarNotReofferedAcrossClosures698=== RUN TestPresignedUploadRegisteredBeforeCommit699=== PAUSE TestPresignedUploadRegisteredBeforeCommit700=== RUN TestService_Rustfstest701=== PAUSE TestService_Rustfstest702=== RUN TestParseSize703=== PAUSE TestParseSize704=== RUN TestSkippedUploadsHandler705=== PAUSE TestSkippedUploadsHandler706=== RUN TestSystemdListenerNotActivated707--- PASS: TestSystemdListenerNotActivated (0.00s)708=== RUN TestWatchdogBeatsWhenHealthy709--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)710=== RUN TestWatchdogSkipsWhenUnhealthy7112026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7172026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7182026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7192026/10/08 12:59:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7202026/10/08 12:59:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"721--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)722=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle723=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle724=== RUN TestProxyWriteTimeout725=== PAUSE TestProxyWriteTimeout726=== RUN TestPendingClosureWriteTimeout727=== PAUSE TestPendingClosureWriteTimeout728=== RUN TestIsValidUploadKey729=== PAUSE TestIsValidUploadKey730=== RUN TestUploadHandlersRejectInvalidKeys731=== PAUSE TestUploadHandlersRejectInvalidKeys732=== RUN TestUploadHandlersRejectOversizedBody733=== PAUSE TestUploadHandlersRejectOversizedBody734=== RUN TestService_cleanupPendingClosuresHandler735=== PAUSE TestService_cleanupPendingClosuresHandler736=== RUN TestService_createPendingClosureHandler737=== PAUSE TestService_createPendingClosureHandler738=== RUN TestService_verifyS3Integrity739=== PAUSE TestService_verifyS3Integrity740=== RUN TestCompleteMultipartUnregistered741=== PAUSE TestCompleteMultipartUnregistered742=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT743=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT744=== CONT TestParseSize745=== CONT TestPush_RejectsBadRequests746=== CONT TestGCTaskStore_CompletedAllowsNewTask747=== CONT TestSkippedUploadsHandler748--- PASS: TestParseSize (0.00s)749--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)750=== CONT TestPresentNotReportedWhileGCDeletesClosure751=== CONT TestService_Rustfstest752=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale753=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale754=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh755=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh756=== CONT TestPresentRefreshesOnlyStaleClosures757=== CONT TestOrphanedObjectsGCStressTest758=== CONT TestPresignedUploadRegisteredBeforeCommit759=== CONT TestCompletedNarNotReofferedAcrossClosures760=== CONT TestCompleteMultipartUpload_ErrorButObjectExists761=== CONT TestUploadHandlersRejectOversizedBody762=== CONT TestRedundantMultipartUpload763=== CONT TestPush_SignsNarinfosOfItsPendingObjects764=== CONT TestCompleteMultipartUnregistered765=== CONT TestService_verifyS3Integrity7662026/10/08 12:59:18 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000767=== CONT TestService_createPendingClosureHandler768=== CONT TestService_cleanupPendingClosuresHandler769=== CONT TestService_AuthMiddleware770=== CONT TestUploadHandlersRejectInvalidKeys771=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info772=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info773=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal774=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal775=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key776=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key777=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key778=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key779=== CONT TestIsValidUploadKey780=== RUN TestIsValidUploadKey/narinfo781=== PAUSE TestIsValidUploadKey/narinfo782=== RUN TestIsValidUploadKey/nar_zst783=== PAUSE TestIsValidUploadKey/nar_zst784=== RUN TestIsValidUploadKey/nar_xz785=== PAUSE TestIsValidUploadKey/nar_xz786=== RUN TestIsValidUploadKey/nar_plain787=== CONT TestPendingClosureWriteTimeout788=== CONT TestProxyWriteTimeout789=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle790=== CONT TestPresentReportsOnlyClosureRoots791=== CONT TestCreatePin_ReservedPins792=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT793--- PASS: TestSkippedUploadsHandler (0.03s)794=== CONT TestOrphanedObjectsGC795=== PAUSE TestIsValidUploadKey/nar_plain796=== RUN TestIsValidUploadKey/listing797=== RUN TestPendingClosureWriteTimeout/empty798=== PAUSE TestPendingClosureWriteTimeout/empty799=== RUN TestPendingClosureWriteTimeout/400_objects800=== PAUSE TestPendingClosureWriteTimeout/400_objects801=== RUN TestPendingClosureWriteTimeout/670k_objects802=== PAUSE TestPendingClosureWriteTimeout/670k_objects803=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline804=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline805=== RUN TestProxyWriteTimeout/narinfo806=== PAUSE TestProxyWriteTimeout/narinfo807=== RUN TestProxyWriteTimeout/1_GiB_nar808=== PAUSE TestProxyWriteTimeout/1_GiB_nar809=== RUN TestProxyWriteTimeout/10_GiB_nar810=== PAUSE TestProxyWriteTimeout/10_GiB_nar811=== RUN TestProxyWriteTimeout/unknown_size812=== PAUSE TestProxyWriteTimeout/unknown_size813=== CONT TestObjectStatsTrigger814=== CONT TestObjectStatsLargeCommit815=== CONT TestPendingCleanupUsesOneCutoff816=== PAUSE TestIsValidUploadKey/listing817=== RUN TestIsValidUploadKey/build_log818=== PAUSE TestIsValidUploadKey/build_log819=== RUN TestIsValidUploadKey/build_log_home-manager_file820=== PAUSE TestIsValidUploadKey/build_log_home-manager_file821=== RUN TestIsValidUploadKey/build_log_plus_in_name822=== PAUSE TestIsValidUploadKey/build_log_plus_in_name823=== RUN TestIsValidUploadKey/build_log_question_mark824=== PAUSE TestIsValidUploadKey/build_log_question_mark825=== RUN TestIsValidUploadKey/build_log_equals826=== PAUSE TestIsValidUploadKey/build_log_equals827=== RUN TestIsValidUploadKey/realisation828=== PAUSE TestIsValidUploadKey/realisation829=== RUN TestIsValidUploadKey/realisation_plus_in_output830=== PAUSE TestIsValidUploadKey/realisation_plus_in_output831=== RUN TestIsValidUploadKey/nix-cache-info832=== PAUSE TestIsValidUploadKey/nix-cache-info833=== RUN TestIsValidUploadKey/index.html834=== PAUSE TestIsValidUploadKey/index.html835=== RUN TestIsValidUploadKey/narinfo_key,_nar_type836=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type837=== RUN TestIsValidUploadKey/nar_key,_narinfo_type838=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type839=== RUN TestIsValidUploadKey/listing_key,_narinfo_type840=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type841=== RUN TestIsValidUploadKey/traversal842=== PAUSE TestIsValidUploadKey/traversal843=== RUN TestIsValidUploadKey/traversal_nar844=== PAUSE TestIsValidUploadKey/traversal_nar845=== RUN TestIsValidUploadKey/absolute846=== PAUSE TestIsValidUploadKey/absolute847=== RUN TestIsValidUploadKey/empty_key848=== PAUSE TestIsValidUploadKey/empty_key849=== RUN TestIsValidUploadKey/unknown_type850=== PAUSE TestIsValidUploadKey/unknown_type851=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded852=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure853=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure854=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart855=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart856=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts857=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts858=== CONT TestMultipartCleanup8592026/10/08 12:59:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53260/oidc8602026/10/08 12:59:19 INFO Received push request method=POST path=/api/pushes8612026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8622026/10/08 12:59:19 INFO Signed narinfos id=1 count=18632026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8642026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/08 12:59:19 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8662026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8672026/10/08 12:59:19 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8682026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8692026/10/08 12:59:19 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18702026/10/08 12:59:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8712026/10/08 12:59:19 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo872--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.84s)873=== CONT TestServerTLSConfig874=== RUN TestServerTLSConfig/no_client_CA875=== PAUSE TestServerTLSConfig/no_client_CA876=== RUN TestServerTLSConfig/missing_CA_file877=== PAUSE TestServerTLSConfig/missing_CA_file878=== RUN TestServerTLSConfig/not_a_PEM_file879=== PAUSE TestServerTLSConfig/not_a_PEM_file880=== CONT TestService_NativeMTLS8812026/10/08 12:59:20 INFO Received uploads request method=POST path=/api/pending_closures8822026/10/08 12:59:20 INFO Received uploads request method=POST path=/api/pending_closures8832026/10/08 12:59:20 INFO Received uploads request method=POST path=/api/pending_closures884=== RUN TestPush_RejectsBadRequests/no_roots885=== PAUSE TestPush_RejectsBadRequests/no_roots886=== RUN TestPush_RejectsBadRequests/no_objects887=== PAUSE TestPush_RejectsBadRequests/no_objects888=== RUN TestPush_RejectsBadRequests/bad_root889=== PAUSE TestPush_RejectsBadRequests/bad_root890=== RUN TestPush_RejectsBadRequests/root_not_in_objects891=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects892=== CONT TestMetricsCommit8932026/10/08 12:59:21 INFO Received uploads request method=POST path=/api/pending_closures8942026/10/08 12:59:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8952026/10/08 12:59:21 INFO Received uploads request method=POST path=/api/pending_closures896--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.39s)897=== CONT TestMetricsInventory898--- PASS: TestService_Rustfstest (3.70s)899=== CONT TestNARDeduplicationMetadataUploadBug9002026/10/08 12:59:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9012026/10/08 12:59:22 INFO Received uploads request method=POST path=/api/pending_closures9022026/10/08 12:59:22 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LmU3NWM4OGExLWQ4YzEtNGM3MC1iYzAyLTU0YzAxMGUyNWJmOXgxNzkxNDY0MzYwMjUwMTEzMDAw parts=109032026/10/08 12:59:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9042026/10/08 12:59:22 INFO Completed upload id=1 objects=2 duration=17.219833ms9052026/10/08 12:59:22 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009062026/10/08 12:59:22 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/08 12:59:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures9082026/10/08 12:59:22 INFO Aborted multipart uploads count=0 kept=09092026/10/08 12:59:22 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09102026/10/08 12:59:22 INFO Vacuumed table table=pending_closures9112026/10/08 12:59:22 INFO Vacuumed table table=pending_objects9122026/10/08 12:59:22 INFO Vacuumed table table=multipart_uploads9132026/10/08 12:59:22 INFO Vacuumed table table=closures9142026/10/08 12:59:22 INFO Vacuumed table table=objects9152026/10/08 12:59:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9162026/10/08 12:59:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LmQ5MjA4OWZkLWUwMWYtNDA5NC05NDBiLTk3MzdkYjBhYmMyYngxNzkxNDY0MzYyNTMyNDQyMDAw9172026/10/08 12:59:22 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000918--- PASS: TestService_createPendingClosureHandler (4.84s)919=== CONT TestCreatePendingClosureRejectsOversizedNAR9202026/10/08 12:59:22 INFO Received uploads request method=POST path=/api/pending_closures921--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)922=== CONT TestCacheConfigHandlerMaxNarSize923--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)924=== CONT TestGenerateLandingPage925--- PASS: TestGenerateLandingPage (0.00s)926=== CONT TestService_readinessHandler9272026/10/08 12:59:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LmQ5MjA4OWZkLWUwMWYtNDA5NC05NDBiLTk3MzdkYjBhYmMyYngxNzkxNDY0MzYyNTMyNDQyMDAw parts=1928--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (4.88s)929=== CONT TestService_healthCheckHandler930--- PASS: TestPresentRefreshesOnlyStaleClosures (4.92s)931=== CONT TestGracefulShutdownDrainsInflight9322026/10/08 12:59:22 INFO Starting HTTP server address=127.0.0.1:533329332026/10/08 12:59:22 INFO Shutdown signal received, draining in-flight requests timeout=10s934--- PASS: TestGracefulShutdownDrainsInflight (0.07s)935=== CONT TestGCTaskStore_Fail936--- PASS: TestGCTaskStore_Fail (0.00s)937=== CONT TestGCTaskStore_PhaseUpdates938--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)939=== CONT TestLeadEndsOnShutdown9402026/10/08 12:59:23 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/08 12:59:23 INFO Received cleanup request method=DELETE path=/api/pending_closures9422026/10/08 12:59:23 INFO Aborted multipart uploads count=0 kept=09432026/10/08 12:59:23 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/08 12:59:23 INFO Received cleanup request method=DELETE path=/api/pending_closures9452026/10/08 12:59:23 INFO Aborted multipart uploads count=1 kept=09462026/10/08 12:59:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9472026-10-08 12:59:23.959 UTC [45204] ERROR: Closure does not exist: id=19482026-10-08 12:59:23.959 UTC [45204] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9492026-10-08 12:59:23.959 UTC [45204] STATEMENT: -- name: CommitPendingClosure :one950 SELECT commit_pending_closure($1::bigint)::bigint951 952--- PASS: TestService_cleanupPendingClosuresHandler (5.92s)953=== CONT TestGCTaskStore_GetReturnsLatest954--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)955=== CONT TestGCTaskStore_GetEmpty956--- PASS: TestGCTaskStore_GetEmpty (0.00s)957=== CONT TestGCTaskStore_ConflictDifferentParams958--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)959=== CONT TestGCTaskStore_DeduplicateSameParams960--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)961=== CONT TestGCTaskStore_StartNew962--- PASS: TestGCTaskStore_StartNew (0.00s)963=== CONT TestGCEndsOnShutdown964=== RUN TestGCEndsOnShutdown/before_the_run965=== PAUSE TestGCEndsOnShutdown/before_the_run966=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete967=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete968=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark969=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark970=== CONT TestCommitRacingPendingCleanupKeepsObjects9712026/10/08 12:59:24 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/08 12:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9732026/10/08 12:59:25 INFO Received uploads request method=POST path=/api/pending_closures974--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (7.24s)975=== CONT TestPushWaitsForSweepHoldingRow9762026/10/08 12:59:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"977--- PASS: TestService_AuthMiddleware (7.61s)978=== CONT TestSweepRechecksPendingAfterLocking9792026/10/08 12:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9802026/10/08 12:59:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4Ljc3ZGI1YWU1LTRlYTktNGNhZi1iNmE3LWI0ZGI5M2M5MWMyYXgxNzkxNDY0MzYzMzU1NjAyMDAw parts=109812026/10/08 12:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9822026/10/08 12:59:25 INFO Completed upload id=1 objects=2 duration=21.959ms9832026/10/08 12:59:25 INFO Received uploads request method=POST path=/api/pending_closures9842026/10/08 12:59:25 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/08 12:59:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9862026/10/08 12:59:25 WARN Found objects in DB but missing from S3, will re-upload count=1987--- PASS: TestService_verifyS3Integrity (7.86s)988=== CONT TestGetExistingObjectsLocksRows989--- PASS: TestObjectStatsTrigger (8.16s)990=== CONT TestRegisterCompletedObjectNeedsPendingRow9912026/10/08 12:59:26 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/08 12:59:27 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/08 12:59:27 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/08 12:59:27 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/08 12:59:27 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/08 12:59:27 INFO Received cleanup request method=DELETE path=/api/pending_closures9972026/10/08 12:59:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/08 12:59:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst999--- PASS: TestCompleteMultipartUnregistered (10.17s)1000=== CONT TestSweepSkipsRowsLockedByPush1001--- PASS: TestPresentReportsOnlyClosureRoots (10.84s)1002=== CONT TestFailedS3DeleteKeepsTombstone10032026/10/08 12:59:28 WARN Rate limiter enabled after throttle name=s3-test rate=510042026/10/08 12:59:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1005=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1006 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101007 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001008--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.91s)1009=== CONT TestForceGCDuringPushOffersSweptObject1010=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1011=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1012=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1013=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1014=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10152026/10/08 12:59:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10162026/10/08 12:59:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LmM0OTAzMzU3LWU4YmYtNDhiOS04NzQwLWUwNTZiM2RhZWExZHgxNzkxNDY0MzY2NzQ2MjkxMDAw parts=1210172026/10/08 12:59:29 INFO Received uploads request method=POST path=/api/pending_closures1018--- PASS: TestCompletedNarNotReofferedAcrossClosures (11.78s)1019=== CONT TestGCSweepDeliversEachKeyOnce10202026/10/08 12:59:29 INFO Received uploads request method=POST path=/api/pending_closures1021--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (11.86s)1022=== CONT TestTombstonedObjectOfferedWithoutWaiting10232026/10/08 12:59:30 INFO Received uploads request method=POST path=/api/pending_closures10242026/10/08 12:59:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10252026/10/08 12:59:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LjM4YjQ1NTZmLTk2MDgtNDYwYi1iOTlhLTlhZjU5ZTc5ODI5YXgxNzkxNDY0MzY3MjUwMDE5MDAw parts=1210262026/10/08 12:59:30 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/08 12:59:30 INFO Received uploads request method=POST path=/api/pending_closures10282026/10/08 12:59:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10292026/10/08 12:59:30 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10302026/10/08 12:59:30 INFO Aborted multipart uploads count=0 kept=110312026/10/08 12:59:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10322026/10/08 12:59:30 INFO Aborted multipart uploads count=1 kept=01033--- PASS: TestMultipartCleanup (12.53s)1034=== CONT TestGCSweepSkipsPendingObjects1035=== NAME TestOrphanedObjectsGC1036 orphaned_objects_gc_test.go:287: GC Test Summary:1037 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1038 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1039 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1040 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1041 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1042--- PASS: TestOrphanedObjectsGC (12.66s)1043=== CONT TestDeduplicatedObjectsRecordedAsPending10442026/10/08 12:59:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10452026/10/08 12:59:30 WARN Refused reserved pin name=worker-x86_64-linux10462026/10/08 12:59:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10472026/10/08 12:59:30 INFO Received create pin request method=POST path=/api/pins/my-app10482026/10/08 12:59:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1049--- PASS: TestCreatePin_ReservedPins (12.77s)1050=== CONT TestPushDedupSurvivesConcurrentGC1051--- PASS: TestMetricsInventory (10.01s)1052=== CONT TestGCMetrics10532026/10/08 12:59:31 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10542026/10/08 12:59:31 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1055--- PASS: TestService_NativeMTLS (11.93s)1056=== CONT TestGCBugBareHashReferences10572026/10/08 12:59:32 INFO Received push request method=POST path=/api/pushes10582026/10/08 12:59:32 INFO Received complete push request method=POST path=/api/pushes/1/complete10592026/10/08 12:59:32 INFO Completed push id=1 objects=4 duration=88.511416ms10602026/10/08 12:59:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10612026/10/08 12:59:32 INFO Completed upload id=2 objects=2 duration=1.10075ms1062--- PASS: TestMetricsCommit (11.86s)1063=== CONT TestGCAdvisoryLockBlocksConcurrentRun1064=== NAME TestNARDeduplicationMetadataUploadBug1065 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/f058402f878f26dd/build/TestNARDeduplicationMetadataUploadBug4288984991/001/store/y97m1d9q25cr3jbr2f8n4gqxpvyakjcg-file1.txt10662026/10/08 12:59:33 INFO lead: acquired remote=192.0.2.1:12341067=== NAME TestOrphanedObjectsGCStressTest1068 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1069 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion10702026/10/08 12:59:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10712026/10/08 12:59:33 INFO Received push request method=POST path=/api/pushes10722026/10/08 12:59:33 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LmU0YWM3ZjU4LTI1MjAtNDM5Zi1hNDVkLTRkNTg3NzVmMzc5MHgxNzkxNDY0MzcwNTI0NjQ0MDAw error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10732026/10/08 12:59:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDUzYjQ1ZmUtMDk3Yy00YjM2LTliOGEtMWE3OTFkNzM1M2Q4LjgxYzY5MGMwLWIzOWEtNGU5Yi1iMTAxLTEwMzExOWFmM2FhOHgxNzkxNDY0MzcwNDQ3MDI4MDAw parts=1210742026/10/08 12:59:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10752026/10/08 12:59:33 INFO Uploading y97m1d9q25cr3jbr2f8n4gqxpvyakjcg-file1.txt (160B)10762026/10/08 12:59:33 INFO Received cleanup request method=DELETE path=/api/pending_closures10772026/10/08 12:59:33 INFO Aborted multipart uploads count=1 kept=010782026/10/08 12:59:33 WARN Failed to register uploaded object key=y97m1d9q25cr3jbr2f8n4gqxpvyakjcg.ls error="server returned 404: 404 page not found\n"10792026/10/08 12:59:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10802026/10/08 12:59:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10812026/10/08 12:59:33 INFO Signed narinfos id=1 count=110822026/10/08 12:59:33 INFO Uploading 1 narinfos1083--- PASS: TestRedundantMultipartUpload (15.27s)1084=== CONT TestClientMultipleUploads10852026/10/08 12:59:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10862026/10/08 12:59:33 WARN Failed to register uploaded object key=y97m1d9q25cr3jbr2f8n4gqxpvyakjcg.narinfo error="server returned 404: 404 page not found\n"10872026/10/08 12:59:33 INFO Completed push id=1 objects=3 duration=25.887416ms10882026/10/08 12:59:33 INFO Upload complete. (326ms)1089=== NAME TestNARDeduplicationMetadataUploadBug1090 metadata_upload_test.go:54: Retrieved narinfo from S3:1091 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestNARDeduplicationMetadataUploadBug4288984991/001/store/y97m1d9q25cr3jbr2f8n4gqxpvyakjcg-file1.txt1092 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1093 Compression: zstd1094 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1095 NarSize: 1601096 References: 1097 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1098 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1099 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1100 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1101--- PASS: TestService_healthCheckHandler (10.60s)1102=== CONT TestLeadIncumbentAnnouncesAtOnce1103=== NAME TestNARDeduplicationMetadataUploadBug1104 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/f058402f878f26dd/build/TestNARDeduplicationMetadataUploadBug4288984991/001/store/zg07vlb6yh2hf30rfhdr5h2f2srxr7h7-file2.txt11052026/10/08 12:59:33 INFO Received push request method=POST path=/api/pushes11062026/10/08 12:59:33 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11072026/10/08 12:59:33 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11082026/10/08 12:59:33 WARN Failed to register uploaded object key=zg07vlb6yh2hf30rfhdr5h2f2srxr7h7.ls error="server returned 404: 404 page not found\n"11092026/10/08 12:59:33 INFO Signed narinfos id=2 count=111102026/10/08 12:59:33 INFO Uploading 1 narinfos11112026/10/08 12:59:33 INFO Received complete push request method=POST path=/api/pushes/2/complete11122026/10/08 12:59:33 WARN Failed to register uploaded object key=zg07vlb6yh2hf30rfhdr5h2f2srxr7h7.narinfo error="server returned 404: 404 page not found\n"11132026/10/08 12:59:33 INFO Completed push id=2 objects=3 duration=693.584µs11142026/10/08 12:59:33 INFO Upload complete. (118ms)1115 metadata_upload_test.go:76: Retrieved narinfo from S3:1116 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestNARDeduplicationMetadataUploadBug4288984991/001/store/zg07vlb6yh2hf30rfhdr5h2f2srxr7h7-file2.txt1117 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1118 Compression: zstd1119 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1120 NarSize: 1601121 References: 1122 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1123 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1124 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1125 {"version":1,"root":{"type":"regular","size":44}}1126--- PASS: TestNARDeduplicationMetadataUploadBug (12.05s)1127=== CONT TestLeadElectsOneAndHandsOver11282026/10/08 12:59:33 WARN readiness check failed error="closed pool"1129--- PASS: TestService_readinessHandler (10.95s)1130=== CONT TestConnectWaitsForAPeerMigration11312026/10/08 12:59:33 INFO Aborted multipart uploads count=1 kept=011322026/10/08 12:59:33 INFO Received cleanup request method=DELETE path=/api/pending_closures11332026/10/08 12:59:33 INFO Aborted multipart uploads count=1 kept=01134--- PASS: TestPendingCleanupUsesOneCutoff (15.90s)1135=== CONT TestResolveDBConnectionString1136=== RUN TestResolveDBConnectionString/flag_wins1137=== PAUSE TestResolveDBConnectionString/flag_wins1138=== RUN TestResolveDBConnectionString/file_when_flag_empty1139=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1140=== RUN TestResolveDBConnectionString/missing_file_is_an_error1141=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1142=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1143=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1144=== RUN TestResolveDBConnectionString/nothing_configured1145=== PAUSE TestResolveDBConnectionString/nothing_configured1146=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11472026/10/08 12:59:34 INFO lead: released remote=192.0.2.1:12341148--- PASS: TestLeadEndsOnShutdown (11.08s)1149=== CONT TestDeleteClosuresRacingPins11502026/10/08 12:59:34 INFO Aborted multipart uploads count=0 kept=011512026/10/08 12:59:34 WARN Force mode enabled - objects will be deleted immediately without grace period11522026/10/08 12:59:34 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=011532026/10/08 12:59:34 INFO Vacuumed table table=pending_closures11542026/10/08 12:59:34 INFO Vacuumed table table=pending_objects11552026/10/08 12:59:34 INFO Vacuumed table table=multipart_uploads11562026/10/08 12:59:34 INFO Vacuumed table table=closures11572026/10/08 12:59:34 INFO Vacuumed table table=objects11582026/10/08 12:59:34 INFO Received uploads request method=POST path=/api/pending_closures1159--- PASS: TestCommitRacingPendingCleanupKeepsObjects (10.68s)1160=== CONT TestClientFallsBackToClosures11612026/10/08 12:59:35 INFO Aborted multipart uploads count=0 kept=011622026/10/08 12:59:35 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/08 12:59:35 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=01164--- PASS: TestPushWaitsForSweepHoldingRow (9.82s)1165=== CONT TestClientPushesUseOnePush11662026/10/08 12:59:35 INFO Vacuumed table table=pending_closures11672026/10/08 12:59:35 INFO Vacuumed table table=pending_objects11682026/10/08 12:59:35 INFO Vacuumed table table=multipart_uploads11692026/10/08 12:59:35 INFO Vacuumed table table=closures11702026/10/08 12:59:35 INFO Vacuumed table table=objects1171--- PASS: TestSweepRechecksPendingAfterLocking (9.53s)1172=== CONT TestPinProtectsFromGC1173--- PASS: TestGetExistingObjectsLocksRows (9.46s)1174=== CONT TestClientSharedPathCommittedMidPush1175--- PASS: TestRegisterCompletedObjectNeedsPendingRow (9.35s)1176=== CONT TestClientWithDependencies11772026/10/08 12:59:36 INFO Aborted multipart uploads count=0 kept=011782026/10/08 12:59:36 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/08 12:59: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=011802026/10/08 12:59:36 INFO Vacuumed table table=pending_closures11812026/10/08 12:59:36 INFO Vacuumed table table=pending_objects11822026/10/08 12:59:36 INFO Vacuumed table table=multipart_uploads11832026/10/08 12:59:36 INFO Vacuumed table table=closures11842026/10/08 12:59:36 INFO Vacuumed table table=objects11852026/10/08 12:59:36 INFO Aborted multipart uploads count=0 kept=011862026/10/08 12:59:36 WARN Force mode enabled - objects will be deleted immediately without grace period11872026/10/08 12:59: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=011882026/10/08 12:59:36 INFO Vacuumed table table=pending_closures11892026/10/08 12:59:36 INFO Vacuumed table table=pending_objects11902026/10/08 12:59:36 INFO Vacuumed table table=multipart_uploads11912026/10/08 12:59:36 INFO Vacuumed table table=closures11922026/10/08 12:59:36 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/08 12:59:36 INFO Vacuumed table table=objects1194--- PASS: TestSweepSkipsRowsLockedByPush (8.13s)1195=== CONT TestReadProxyRootRedirectsToIndexHTML11962026/10/08 12:59:36 INFO Aborted multipart uploads count=0 kept=011972026/10/08 12:59:36 WARN Force mode enabled - objects will be deleted immediately without grace period11982026/10/08 12:59:36 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11992026/10/08 12:59:36 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1200--- PASS: TestFailedS3DeleteKeepsTombstone (7.67s)1201=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12022026/10/08 12:59:36 INFO Received uploads request method=POST path=/api/pending_closures1203--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (8.01s)1204=== CONT TestPush_RootsAreLockedInByteOrder1205{"timestamp":"2026-10-08T12:59:37.091853Z","level":"ERROR","message":"save_config_with_opts: err: Io(Custom { kind: TooManyOpenFiles, error: \"Too many open files (os error 24)\" }), file: buckets/bucket43/.bucket-incarnation","target":"rustfs_ecstore::config::com","filename":"crates/ecstore/src/config/com.rs","line_number":813,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}1206{"timestamp":"2026-10-08T12:59:37.09327Z","level":"ERROR","message":"Heal scheduler task failed","event":"heal_scheduler_state","component":"heal","subsystem":"manager","task_id":"4f74abdc-bccc-4cd2-adfe-cd35c73072df","heal_type":"object","set":"pool_0_set_0","state":"task_failed","error":"Heal task execution failed: Object not found: .rustfs.sys/buckets/bucket43/.bucket-incarnation","target":"rustfs::heal::manager","filename":"crates/heal/src/heal/manager/scheduler.rs","line_number":269,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}1207{"timestamp":"2026-10-08T12:59:37.135491Z","level":"ERROR","duration":"411.884416ms","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(8)"}1208{"timestamp":"2026-10-08T12:59:37.135586Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4c700d5c-4a84-42ef-88ce-e82483f7a9da","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket43/","status_code":500,"suppressed_errors":0,"duration_ms":412,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}1209=== NAME TestOrphanedObjectsGCStressTest1210 orphaned_objects_gc_test.go:503: Stress test completed successfully:1211 orphaned_objects_gc_test.go:504: - Active objects preserved: 201212 orphaned_objects_gc_test.go:505: - Objects deleted: 2101213 orphaned_objects_gc_test.go:506: - Total GC'd: 2101214--- PASS: TestOrphanedObjectsGCStressTest (19.13s)1215=== CONT TestPush_CompleteWaitsForCleanupOfThePush1216--- PASS: TestObjectStatsLargeCommit (19.15s)1217=== CONT TestPush_RepeatedRootCommitsOnce12182026/10/08 12:59:37 INFO Aborted multipart uploads count=0 kept=012192026/10/08 12:59:37 WARN Force mode enabled - objects will be deleted immediately without grace period12202026/10/08 12:59:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012212026/10/08 12:59:37 INFO Vacuumed table table=pending_closures12222026/10/08 12:59:37 INFO Vacuumed table table=pending_objects12232026/10/08 12:59:37 INFO Vacuumed table table=multipart_uploads12242026/10/08 12:59:37 INFO Vacuumed table table=closures12252026/10/08 12:59:38 INFO Received uploads request method=POST path=/api/pending_closures12262026/10/08 12:59:38 INFO Vacuumed table table=objects1227--- PASS: TestGCSweepDeliversEachKeyOnce (8.21s)1228=== CONT TestPush_CompleteCommitsEveryRoot1229--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.10s)1230=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12312026/10/08 12:59:38 INFO Received uploads request method=POST path=/api/pending_closures1232--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.77s)1233=== CONT TestReadRedirectUsesPublicS3URL12342026/10/08 12:59:38 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/08 12:59:38 INFO Aborted multipart uploads count=0 kept=012362026/10/08 12:59:39 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/10/08 12:59: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=012382026/10/08 12:59:39 INFO Vacuumed table table=pending_closures12392026/10/08 12:59:39 INFO Vacuumed table table=pending_objects12402026/10/08 12:59:39 INFO Vacuumed table table=multipart_uploads12412026/10/08 12:59:39 INFO Vacuumed table table=closures12422026/10/08 12:59:39 INFO Vacuumed table table=objects1243--- PASS: TestGCSweepSkipsPendingObjects (8.56s)1244=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale12452026/10/08 12:59:39 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/08 12:59:39 INFO Aborted multipart uploads count=0 kept=012472026/10/08 12:59:39 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=012482026/10/08 12:59:39 INFO Aborted multipart uploads count=0 kept=012492026/10/08 12:59:39 INFO Vacuumed table table=pending_closures12502026/10/08 12:59:39 WARN Force mode enabled - objects will be deleted immediately without grace period12512026/10/08 12:59: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=012522026/10/08 12:59:39 INFO Vacuumed table table=pending_closures12532026/10/08 12:59:39 INFO Vacuumed table table=pending_objects12542026/10/08 12:59:39 INFO Vacuumed table table=pending_objects12552026/10/08 12:59:39 INFO Vacuumed table table=multipart_uploads12562026/10/08 12:59:39 INFO Vacuumed table table=multipart_uploads12572026/10/08 12:59:39 INFO Vacuumed table table=closures12582026/10/08 12:59:39 INFO Vacuumed table table=objects1259--- PASS: TestGCMetrics (8.31s)1260=== CONT TestReadProxyRangeRequest12612026/10/08 12:59:39 INFO Vacuumed table table=closures12622026/10/08 12:59:39 INFO Vacuumed table table=objects12632026/10/08 12:59:39 INFO Aborted multipart uploads count=0 kept=012642026/10/08 12:59:39 WARN Force mode enabled - objects will be deleted immediately without grace period12652026/10/08 12:59: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=012662026/10/08 12:59:39 INFO Vacuumed table table=pending_closures12672026/10/08 12:59:39 INFO Vacuumed table table=pending_objects12682026/10/08 12:59:39 INFO Vacuumed table table=multipart_uploads12692026/10/08 12:59:39 INFO Vacuumed table table=closures12702026/10/08 12:59:39 INFO Vacuumed table table=objects1271--- PASS: TestPushDedupSurvivesConcurrentGC (9.05s)1272=== CONT TestReadProxyConditionalGet1273--- PASS: TestGCBugBareHashReferences (8.54s)1274=== CONT TestReadRedirectKeepsNarinfoProxied12752026/10/08 12:59:40 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1276--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.94s)1277=== CONT TestReadProxyOutlastsServerWriteTimeout1278=== NAME TestClientMultipleUploads12792026/10/08 12:59:41 INFO lead: acquired remote=192.0.2.1:12341280 client_integration_test.go:358: Created store path 0: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientMultipleUploads2911288537/001/store/iz0230zgkcy9ynwk29bzl8srjdr31cn9-test-file-0.txt12812026/10/08 12:59:41 INFO lead: released remote=192.0.2.1:12341282--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.80s)1283=== CONT TestReadRedirectNar1284=== NAME TestClientMultipleUploads1285 client_integration_test.go:358: Created store path 1: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientMultipleUploads2911288537/001/store/qxh5gka9v1w8251plf37vvwjp1j8d2lw-test-file-1.txt1286 client_integration_test.go:358: Created store path 2: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientMultipleUploads2911288537/001/store/31rm8glzv491369a1hjpw4jnzd0nj4ai-test-file-2.txt12872026/10/08 12:59:41 INFO lead: acquired remote=192.0.2.1:123412882026/10/08 12:59:41 INFO Received push request method=POST path=/api/pushes12892026/10/08 12:59:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12902026/10/08 12:59:41 INFO Uploading qxh5gka9v1w8251plf37vvwjp1j8d2lw-test-file-1.txt (160B)12912026/10/08 12:59:41 INFO Uploading iz0230zgkcy9ynwk29bzl8srjdr31cn9-test-file-0.txt (160B)12922026/10/08 12:59:41 INFO Uploading 31rm8glzv491369a1hjpw4jnzd0nj4ai-test-file-2.txt (160B)12932026/10/08 12:59:41 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12942026/10/08 12:59:41 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12952026/10/08 12:59:41 WARN Failed to register uploaded object key=iz0230zgkcy9ynwk29bzl8srjdr31cn9.ls error="server returned 404: 404 page not found\n"12962026/10/08 12:59:41 WARN Failed to register uploaded object key=31rm8glzv491369a1hjpw4jnzd0nj4ai.ls error="server returned 404: 404 page not found\n"12972026/10/08 12:59:41 WARN Failed to register uploaded object key=qxh5gka9v1w8251plf37vvwjp1j8d2lw.ls error="server returned 404: 404 page not found\n"12982026/10/08 12:59:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12992026/10/08 12:59:41 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13002026/10/08 12:59:41 INFO Signed narinfos id=1 count=313012026/10/08 12:59:41 INFO Uploading 3 narinfos13022026/10/08 12:59:41 WARN Failed to register uploaded object key=31rm8glzv491369a1hjpw4jnzd0nj4ai.narinfo error="server returned 404: 404 page not found\n"13032026/10/08 12:59:41 WARN Failed to register uploaded object key=iz0230zgkcy9ynwk29bzl8srjdr31cn9.narinfo error="server returned 404: 404 page not found\n"13042026/10/08 12:59:41 INFO Received complete push request method=POST path=/api/pushes/1/complete13052026/10/08 12:59:41 WARN Failed to register uploaded object key=qxh5gka9v1w8251plf37vvwjp1j8d2lw.narinfo error="server returned 404: 404 page not found\n"13062026/10/08 12:59:41 INFO Completed push id=1 objects=9 duration=37.3635ms13072026/10/08 12:59:41 INFO Upload complete. (231ms)1308 client_integration_test.go:369: Uploaded 3 paths in 277.365333ms1309--- PASS: TestConnectWaitsForAPeerMigration (8.12s)1310=== CONT TestReadProxyHead1311--- PASS: TestClientMultipleUploads (8.77s)1312=== CONT TestReadProxyDisabled13132026/10/08 12:59:42 INFO lead: released remote=192.0.2.1:123413142026/10/08 12:59:42 INFO lead: acquired remote=192.0.2.1:12341315--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (9.68s)13162026/10/08 12:59:43 INFO Received uploads request method=POST path=/api/pending_closures1317=== CONT TestReadProxyInvalidPath13182026/10/08 12:59:43 INFO Received uploads request method=POST path=/api/pending_closures13192026/10/08 12:59:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13202026/10/08 12:59:43 INFO Uploading vr16kjng3nigjlxg881yq8l62xdfacwa-b (256B)13212026/10/08 12:59:43 INFO Uploading kazzg1yl067nmhmi8jd2b51x3qknx8kb-shared-dep (136B)13222026/10/08 12:59:43 WARN Failed to register uploaded object key=nar/1n6cciywizmdvnghp14bkvasxdkl97i02jyr036w0g2k7yykjwhm.nar.zst error="server returned 404: 404 page not found\n"13232026/10/08 12:59:43 WARN Failed to register uploaded object key=kazzg1yl067nmhmi8jd2b51x3qknx8kb.ls error="server returned 404: 404 page not found\n"13242026/10/08 12:59:43 WARN Failed to register uploaded object key=n749z5saprzg8r1rack0m52pf1i6mdx7.ls error="server returned 404: 404 page not found\n"13252026/10/08 12:59:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13262026/10/08 12:59:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13272026/10/08 12:59:43 WARN Failed to register uploaded object key=vr16kjng3nigjlxg881yq8l62xdfacwa.ls error="server returned 404: 404 page not found\n"13282026/10/08 12:59:43 INFO Signed narinfos id=1 count=213292026/10/08 12:59:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13302026/10/08 12:59:43 INFO Signed narinfos id=2 count=213312026/10/08 12:59:43 INFO Uploading 4 narinfos1332=== NAME TestPinProtectsFromGC1333 client_integration_test.go:731: Pinned store path: /private/var/tb/8/scratch/f058402f878f26dd/build/TestPinProtectsFromGC4181760145/001/store/z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a-pinned-file.txt1334 client_integration_test.go:732: Unpinned store path: /private/var/tb/8/scratch/f058402f878f26dd/build/TestPinProtectsFromGC4181760145/001/store/cbli1i3j83mp7szgz7ziq3yhr2js0zwq-unpinned-file.txt13352026/10/08 12:59:43 WARN Failed to register uploaded object key=kazzg1yl067nmhmi8jd2b51x3qknx8kb.narinfo error="server returned 404: 404 page not found\n"13362026/10/08 12:59:43 WARN Failed to register uploaded object key=vr16kjng3nigjlxg881yq8l62xdfacwa.narinfo error="server returned 404: 404 page not found\n"13372026/10/08 12:59:43 WARN Failed to register uploaded object key=n749z5saprzg8r1rack0m52pf1i6mdx7.narinfo error="server returned 404: 404 page not found\n"13382026/10/08 12:59:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13392026/10/08 12:59:43 WARN Failed to register uploaded object key=kazzg1yl067nmhmi8jd2b51x3qknx8kb.narinfo error="server returned 404: 404 page not found\n"13402026/10/08 12:59:43 INFO Completed upload id=1 objects=6 duration=36.536667ms13412026/10/08 12:59:43 INFO Received push request method=POST path=/api/pushes13422026/10/08 12:59:43 INFO lead: released remote=192.0.2.1:12341343--- PASS: TestLeadElectsOneAndHandsOver (10.18s)13442026/10/08 12:59:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1345=== CONT TestReadProxy40413462026/10/08 12:59:43 INFO Completed upload id=2 objects=6 duration=572.375µs13472026/10/08 12:59:43 INFO Upload complete. (336ms)1348=== NAME TestClientFallsBackToClosures1349 client_pushes_test.go:112: Retrieved narinfo from S3:1350 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientFallsBackToClosures2927289381/001/store/kazzg1yl067nmhmi8jd2b51x3qknx8kb-shared-dep1351 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1352 Compression: zstd1353 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821354 NarSize: 1361355 References: 1356 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1357 client_pushes_test.go:112: Retrieved narinfo from S3:1358 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientFallsBackToClosures2927289381/001/store/n749z5saprzg8r1rack0m52pf1i6mdx7-a1359 URL: nar/1n6cciywizmdvnghp14bkvasxdkl97i02jyr036w0g2k7yykjwhm.nar.zst1360 Compression: zstd1361 NarHash: sha256:1n6cciywizmdvnghp14bkvasxdkl97i02jyr036w0g2k7yykjwhm1362 NarSize: 2561363 References: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientFallsBackToClosures2927289381/001/store/kazzg1yl067nmhmi8jd2b51x3qknx8kb-shared-dep1364 CA: text:sha256:0zhqny3phmlkkvrlgmdw116l2zznkl3sb0m94lx4fi2brqfn6lg91365 client_pushes_test.go:112: Retrieved narinfo from S3:1366 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientFallsBackToClosures2927289381/001/store/vr16kjng3nigjlxg881yq8l62xdfacwa-b1367 URL: nar/1n6cciywizmdvnghp14bkvasxdkl97i02jyr036w0g2k7yykjwhm.nar.zst1368 Compression: zstd1369 NarHash: sha256:1n6cciywizmdvnghp14bkvasxdkl97i02jyr036w0g2k7yykjwhm1370 NarSize: 2561371 References: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientFallsBackToClosures2927289381/001/store/kazzg1yl067nmhmi8jd2b51x3qknx8kb-shared-dep1372 CA: text:sha256:0zhqny3phmlkkvrlgmdw116l2zznkl3sb0m94lx4fi2brqfn6lg913732026/10/08 12:59:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13742026/10/08 12:59:44 INFO Uploading z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a-pinned-file.txt (128B)1375--- PASS: TestClientFallsBackToClosures (9.38s)1376=== CONT TestIsValidCachePath1377=== RUN TestIsValidCachePath/narinfo1378=== PAUSE TestIsValidCachePath/narinfo1379=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1380=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1381=== RUN TestIsValidCachePath/nar_zst1382=== PAUSE TestIsValidCachePath/nar_zst1383=== RUN TestIsValidCachePath/nar_xz1384=== PAUSE TestIsValidCachePath/nar_xz1385=== RUN TestIsValidCachePath/nar_bz21386=== PAUSE TestIsValidCachePath/nar_bz21387=== RUN TestIsValidCachePath/nar_uncompressed1388=== PAUSE TestIsValidCachePath/nar_uncompressed1389=== RUN TestIsValidCachePath/ls1390=== PAUSE TestIsValidCachePath/ls1391=== RUN TestIsValidCachePath/log1392=== PAUSE TestIsValidCachePath/log1393=== RUN TestIsValidCachePath/realisation1394=== PAUSE TestIsValidCachePath/realisation1395=== RUN TestIsValidCachePath/nix-cache-info1396=== PAUSE TestIsValidCachePath/nix-cache-info1397=== RUN TestIsValidCachePath/index.html1398=== PAUSE TestIsValidCachePath/index.html1399=== RUN TestIsValidCachePath/traversal_parent1400=== PAUSE TestIsValidCachePath/traversal_parent1401=== RUN TestIsValidCachePath/traversal_in_middle1402=== PAUSE TestIsValidCachePath/traversal_in_middle1403=== RUN TestIsValidCachePath/invalid_char_e1404=== PAUSE TestIsValidCachePath/invalid_char_e1405=== RUN TestIsValidCachePath/invalid_char_u1406=== PAUSE TestIsValidCachePath/invalid_char_u1407=== RUN TestIsValidCachePath/random_path1408=== PAUSE TestIsValidCachePath/random_path1409=== RUN TestIsValidCachePath/empty1410=== PAUSE TestIsValidCachePath/empty1411=== RUN TestIsValidCachePath/leading_slash1412=== PAUSE TestIsValidCachePath/leading_slash1413=== RUN TestIsValidCachePath/wrong_extension1414=== PAUSE TestIsValidCachePath/wrong_extension1415=== RUN TestIsValidCachePath/short_hash1416=== PAUSE TestIsValidCachePath/short_hash1417=== CONT TestParseSingleRange14182026/10/08 12:59:44 WARN Failed to register uploaded object key=z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a.ls error="server returned 404: 404 page not found\n"1419=== RUN TestParseSingleRange/none1420=== PAUSE TestParseSingleRange/none14212026/10/08 12:59:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14222026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1423=== RUN TestParseSingleRange/unknown_unit1424=== PAUSE TestParseSingleRange/unknown_unit1425=== RUN TestParseSingleRange/multi-range_ignored1426=== PAUSE TestParseSingleRange/multi-range_ignored1427=== RUN TestParseSingleRange/malformed_no_dash1428=== PAUSE TestParseSingleRange/malformed_no_dash1429=== RUN TestParseSingleRange/malformed_both_empty1430=== PAUSE TestParseSingleRange/malformed_both_empty1431=== RUN TestParseSingleRange/malformed_end_before_start1432=== PAUSE TestParseSingleRange/malformed_end_before_start1433=== RUN TestParseSingleRange/closed1434=== PAUSE TestParseSingleRange/closed1435=== RUN TestParseSingleRange/open-ended1436=== PAUSE TestParseSingleRange/open-ended1437=== RUN TestParseSingleRange/end_clamped_to_size1438=== PAUSE TestParseSingleRange/end_clamped_to_size1439=== RUN TestParseSingleRange/suffix1440=== PAUSE TestParseSingleRange/suffix1441=== RUN TestParseSingleRange/suffix_exceeds_size1442=== PAUSE TestParseSingleRange/suffix_exceeds_size1443=== RUN TestParseSingleRange/single_byte1444=== PAUSE TestParseSingleRange/single_byte1445=== RUN TestParseSingleRange/start_past_EOF1446=== PAUSE TestParseSingleRange/start_past_EOF1447=== RUN TestParseSingleRange/start_far_past_EOF1448=== PAUSE TestParseSingleRange/start_far_past_EOF1449=== CONT TestReadProxyNarStreaming14502026/10/08 12:59:44 INFO Signed narinfos id=1 count=114512026/10/08 12:59:44 INFO Uploading 1 narinfos14522026/10/08 12:59:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14532026/10/08 12:59:44 WARN Failed to register uploaded object key=z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a.narinfo error="server returned 404: 404 page not found\n"14542026/10/08 12:59:44 INFO Completed push id=1 objects=3 duration=26.689625ms14552026/10/08 12:59:44 INFO Upload complete. (266ms)14562026/10/08 12:59:44 INFO Received push request method=POST path=/api/pushes14572026/10/08 12:59:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/10/08 12:59:44 INFO Uploading cbli1i3j83mp7szgz7ziq3yhr2js0zwq-unpinned-file.txt (128B)14592026/10/08 12:59:44 WARN Failed to register uploaded object key=cbli1i3j83mp7szgz7ziq3yhr2js0zwq.ls error="server returned 404: 404 page not found\n"14602026/10/08 12:59:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14612026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14622026/10/08 12:59:44 INFO Signed narinfos id=2 count=114632026/10/08 12:59:44 INFO Uploading 1 narinfos14642026/10/08 12:59:44 INFO Received complete push request method=POST path=/api/pushes/2/complete14652026/10/08 12:59:44 WARN Failed to register uploaded object key=cbli1i3j83mp7szgz7ziq3yhr2js0zwq.narinfo error="server returned 404: 404 page not found\n"14662026/10/08 12:59:44 INFO Completed push id=2 objects=3 duration=791.666µs14672026/10/08 12:59:44 INFO Upload complete. (117ms)14682026/10/08 12:59:44 INFO Received push request method=POST path=/api/pushes14692026/10/08 12:59:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures14702026/10/08 12:59:44 INFO Garbage collection started14712026/10/08 12:59:44 INFO Aborted multipart uploads count=0 kept=014722026/10/08 12:59:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14732026/10/08 12:59:44 INFO Uploading b86nan5phv27mhkb0a8zd6adh3viv3is-a (256B)14742026/10/08 12:59:44 INFO Uploading anawnw1z1f8dxwrgcx19n8f9drrcij8h-shared-dep (136B)14752026/10/08 12:59:44 WARN Force mode enabled - objects will be deleted immediately without grace period14762026/10/08 12:59:44 WARN Failed to register uploaded object key=4fbdngavabnvw8p104l0gxsgwq6yz7rh.ls error="server returned 404: 404 page not found\n"14772026/10/08 12:59:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14782026/10/08 12:59:44 WARN Failed to register uploaded object key=b86nan5phv27mhkb0a8zd6adh3viv3is.ls error="server returned 404: 404 page not found\n"14792026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14802026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/1d8sb1w981kmwyygddhyfyj15azaj17bl9bb5pix40g6hb8qgifh.nar.zst error="server returned 404: 404 page not found\n"14812026/10/08 12:59:44 WARN Failed to register uploaded object key=anawnw1z1f8dxwrgcx19n8f9drrcij8h.ls error="server returned 404: 404 page not found\n"14822026/10/08 12:59:44 INFO Signed narinfos id=1 count=314832026/10/08 12:59:44 INFO Uploading 3 narinfos14842026/10/08 12:59:44 WARN Failed to register uploaded object key=4fbdngavabnvw8p104l0gxsgwq6yz7rh.narinfo error="server returned 404: 404 page not found\n"14852026/10/08 12:59:44 WARN Failed to register uploaded object key=b86nan5phv27mhkb0a8zd6adh3viv3is.narinfo error="server returned 404: 404 page not found\n"14862026/10/08 12:59:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14872026/10/08 12:59:44 WARN Failed to register uploaded object key=anawnw1z1f8dxwrgcx19n8f9drrcij8h.narinfo error="server returned 404: 404 page not found\n"14882026/10/08 12:59:44 INFO Completed push id=1 objects=8 duration=26.339334ms14892026/10/08 12:59:44 INFO Upload complete. (260ms)14902026/10/08 12:59:44 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=01491=== NAME TestClientPushesUseOnePush1492 client_pushes_test.go:97: Retrieved narinfo from S3:1493 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientPushesUseOnePush2357509665/001/store/anawnw1z1f8dxwrgcx19n8f9drrcij8h-shared-dep1494 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1495 Compression: zstd1496 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821497 NarSize: 1361498 References: 1499 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1500 client_pushes_test.go:97: Retrieved narinfo from S3:1501 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientPushesUseOnePush2357509665/001/store/b86nan5phv27mhkb0a8zd6adh3viv3is-a1502 URL: nar/1d8sb1w981kmwyygddhyfyj15azaj17bl9bb5pix40g6hb8qgifh.nar.zst1503 Compression: zstd1504 NarHash: sha256:1d8sb1w981kmwyygddhyfyj15azaj17bl9bb5pix40g6hb8qgifh1505 NarSize: 2561506 References: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientPushesUseOnePush2357509665/001/store/anawnw1z1f8dxwrgcx19n8f9drrcij8h-shared-dep1507 CA: text:sha256:0fimc055asv0wbjy3fiahcvbscc90cl0bpnsznz21ihlbffzvjyb1508 client_pushes_test.go:97: Retrieved narinfo from S3:1509 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientPushesUseOnePush2357509665/001/store/4fbdngavabnvw8p104l0gxsgwq6yz7rh-b1510 URL: nar/1d8sb1w981kmwyygddhyfyj15azaj17bl9bb5pix40g6hb8qgifh.nar.zst1511 Compression: zstd1512 NarHash: sha256:1d8sb1w981kmwyygddhyfyj15azaj17bl9bb5pix40g6hb8qgifh1513 NarSize: 2561514 References: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientPushesUseOnePush2357509665/001/store/anawnw1z1f8dxwrgcx19n8f9drrcij8h-shared-dep1515 CA: text:sha256:0fimc055asv0wbjy3fiahcvbscc90cl0bpnsznz21ihlbffzvjyb15162026/10/08 12:59:44 INFO Vacuumed table table=pending_closures15172026/10/08 12:59:44 INFO Received push request method=POST path=/api/pushes15182026/10/08 12:59:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15192026/10/08 12:59:44 INFO Uploading 34q9rqqq2yd2l2zbpiw2ym0928d56hmk-shared-dep (136B)15202026/10/08 12:59:44 INFO Uploading 0zq5dyfq4x4bd186c5wnckr7inh961l2-top (264B)15212026/10/08 12:59:44 INFO Vacuumed table table=pending_objects15222026/10/08 12:59:44 INFO Vacuumed table table=multipart_uploads1523--- PASS: TestClientPushesUseOnePush (9.51s)15242026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1525=== CONT TestReadProxyContentNegotiation15262026/10/08 12:59:44 WARN Failed to register uploaded object key=34q9rqqq2yd2l2zbpiw2ym0928d56hmk.ls error="server returned 404: 404 page not found\n"15272026/10/08 12:59:44 WARN Failed to register uploaded object key=0zq5dyfq4x4bd186c5wnckr7inh961l2.ls error="server returned 404: 404 page not found\n"15282026/10/08 12:59:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15292026/10/08 12:59:44 WARN Failed to register uploaded object key=nar/0yab15yrpgz9scwz0xdna9qgm2wsmdx50g2v5ji98scng90j6ph9.nar.zst error="server returned 404: 404 page not found\n"15302026/10/08 12:59:44 INFO Signed narinfos id=1 count=215312026/10/08 12:59:44 INFO Vacuumed table table=closures15322026/10/08 12:59:44 INFO Uploading 2 narinfos15332026/10/08 12:59:44 INFO Vacuumed table table=objects15342026/10/08 12:59:44 WARN Failed to register uploaded object key=0zq5dyfq4x4bd186c5wnckr7inh961l2.narinfo error="server returned 404: 404 page not found\n"15352026/10/08 12:59:44 INFO Received complete push request method=POST path=/api/pushes/1/complete15362026/10/08 12:59:44 WARN Failed to register uploaded object key=34q9rqqq2yd2l2zbpiw2ym0928d56hmk.narinfo error="server returned 404: 404 page not found\n"15372026/10/08 12:59:44 INFO Completed push id=1 objects=6 duration=27.563959ms15382026/10/08 12:59:44 INFO Upload complete. (276ms)1539=== NAME TestClientSharedPathCommittedMidPush1540 client_integration_test.go:680: Retrieved narinfo from S3:1541 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientSharedPathCommittedMidPush2431481064/001/store/34q9rqqq2yd2l2zbpiw2ym0928d56hmk-shared-dep1542 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1543 Compression: zstd1544 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821545 NarSize: 1361546 References: 1547 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1548--- PASS: TestReadProxyRootRedirectsToIndexHTML (8.43s)1549=== CONT TestReadProxyNarinfoAlreadyDecompressed1550=== NAME TestClientSharedPathCommittedMidPush1551 client_integration_test.go:680: Retrieved narinfo from S3:1552 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientSharedPathCommittedMidPush2431481064/001/store/0zq5dyfq4x4bd186c5wnckr7inh961l2-top1553 URL: nar/0yab15yrpgz9scwz0xdna9qgm2wsmdx50g2v5ji98scng90j6ph9.nar.zst1554 Compression: zstd1555 NarHash: sha256:0yab15yrpgz9scwz0xdna9qgm2wsmdx50g2v5ji98scng90j6ph91556 NarSize: 2641557 References: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientSharedPathCommittedMidPush2431481064/001/store/34q9rqqq2yd2l2zbpiw2ym0928d56hmk-shared-dep1558 CA: text:sha256:0hdgd6wqgi2m94nn5kh46h8ianjlps9qprx8k0mkswa7g4zqdal71559--- PASS: TestClientSharedPathCommittedMidPush (9.51s)1560=== CONT TestReadProxyNarinfo1561=== NAME TestClientWithDependencies1562 client_integration_test.go:613: Built derivation: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientWithDependencies2886328443/001/store/w7nm6866dyyskxsn6xsza9msi4gmbq20-test-script1563 client_integration_test.go:615: Found 1 dependencies (including self)15642026/10/08 12:59:45 INFO Received push request method=POST path=/api/pushes15652026/10/08 12:59:45 INFO Received push request method=POST path=/api/pushes15662026/10/08 12:59:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15672026/10/08 12:59:45 INFO Uploading w7nm6866dyyskxsn6xsza9msi4gmbq20-test-script (136B)15682026/10/08 12:59:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15692026/10/08 12:59:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15702026/10/08 12:59:45 WARN Failed to register uploaded object key=w7nm6866dyyskxsn6xsza9msi4gmbq20.ls error="server returned 404: 404 page not found\n"15712026/10/08 12:59:45 WARN Failed to register uploaded object key=log/1ipsidf0a9jwxmjj5p9b1g9q86j7kq96-test-script.drv error="server returned 404: 404 page not found\n"15722026/10/08 12:59:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15732026/10/08 12:59:45 INFO Signed narinfos id=1 count=115742026/10/08 12:59:45 INFO Uploading 1 narinfos15752026/10/08 12:59:45 INFO Completed push id=1 objects=4 duration=43.57625ms15762026/10/08 12:59:45 INFO Received push request method=POST path=/api/pushes15772026/10/08 12:59:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/08 12:59:45 WARN Failed to register uploaded object key=w7nm6866dyyskxsn6xsza9msi4gmbq20.narinfo error="server returned 404: 404 page not found\n"15792026/10/08 12:59:45 INFO Completed push id=1 objects=4 duration=27.699167ms15802026/10/08 12:59:45 INFO Upload complete. (232ms)1581 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/f058402f878f26dd/build/TestClientWithDependencies2886328443/001/store) requires matching store prefix15822026/10/08 12:59:45 INFO Aborted multipart uploads count=0 kept=015832026/10/08 12:59:45 WARN Force mode enabled - objects will be deleted immediately without grace period15842026/10/08 12:59:45 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=015852026/10/08 12:59:45 INFO Vacuumed table table=pending_closures1586--- PASS: TestClientWithDependencies (9.79s)1587=== CONT TestService_ReadScope_PublicByDefault15882026/10/08 12:59:45 INFO Vacuumed table table=pending_objects15892026/10/08 12:59:45 INFO Received push request method=POST path=/api/pushes15902026/10/08 12:59:45 INFO Vacuumed table table=multipart_uploads15912026/10/08 12:59:45 INFO Vacuumed table table=closures15922026/10/08 12:59:45 INFO Vacuumed table table=objects15932026/10/08 12:59:45 INFO Received complete push request method=POST path=/api/pushes/2/complete15942026/10/08 12:59:45 INFO Completed push id=2 objects=4 duration=7.351875ms1595--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (9.00s)1596=== CONT TestClientIntegration15972026-10-08 12:59:45.632 UTC [45583] ERROR: could not obtain lock on row in relation "closures"15982026-10-08 12:59:45.632 UTC [45583] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15992026-10-08 12:59:45.636 UTC [45583] ERROR: could not obtain lock on row in relation "closures"16002026-10-08 12:59:45.636 UTC [45583] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16012026-10-08 12:59:45.637 UTC [45583] ERROR: could not obtain lock on row in relation "closures"16022026-10-08 12:59:45.637 UTC [45583] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16032026-10-08 12:59:45.638 UTC [45583] ERROR: could not obtain lock on row in relation "closures"16042026-10-08 12:59:45.638 UTC [45583] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16052026-10-08 12:59:45.642 UTC [45583] ERROR: could not obtain lock on row in relation "closures"16062026-10-08 12:59:45.642 UTC [45583] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1607--- PASS: TestPush_RootsAreLockedInByteOrder (8.63s)1608=== CONT TestClientErrorHandling1609=== RUN TestClientErrorHandling/InvalidStorePath1610=== PAUSE TestClientErrorHandling/InvalidStorePath1611=== RUN TestClientErrorHandling/InvalidAuthToken1612=== PAUSE TestClientErrorHandling/InvalidAuthToken1613=== RUN TestClientErrorHandling/ServerNotAvailable1614=== PAUSE TestClientErrorHandling/ServerNotAvailable1615=== CONT TestClientCADerivations16162026/10/08 12:59:45 INFO Received push request method=POST path=/api/pushes16172026/10/08 12:59:46 INFO Received push request method=POST path=/api/pushes16182026-10-08 12:59:46.166 UTC [45591] ERROR: Push does not exist: id=116192026-10-08 12:59:46.166 UTC [45591] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16202026-10-08 12:59:46.166 UTC [45591] STATEMENT: SELECT commit_push($1)1621--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.01s)1622=== CONT TestCacheStatsHandler16232026/10/08 12:59:46 INFO Received complete push request method=POST path=/api/pushes/1/complete16242026/10/08 12:59:46 INFO Completed push id=1 objects=4 duration=32.624208ms1625--- PASS: TestPush_RepeatedRootCommitsOnce (9.06s)1626=== CONT TestCacheConfigHandler1627=== RUN TestCacheConfigHandler/full_config,_no_issuer1628=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1629=== RUN TestCacheConfigHandler/no_cache_url_configured1630=== PAUSE TestCacheConfigHandler/no_cache_url_configured1631=== RUN TestCacheConfigHandler/no_signing_keys1632=== PAUSE TestCacheConfigHandler/no_signing_keys1633=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1634=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1635=== CONT TestService_ReadAuthMiddleware16362026/10/08 12:59:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016372026/10/08 12:59:46 INFO Received create pin request method=POST path=/api/pins/myapp16382026/10/08 12:59:46 INFO Received push request method=POST path=/api/pushes16392026/10/08 12:59:46 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestPinProtectsFromGC4181760145/001/store/z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a-pinned-file.txt narinfo_key=z5gn0hlkhmajx3l49k9ixm7p3bcbiz8a.narinfo16402026/10/08 12:59:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures16412026/10/08 12:59:46 INFO Garbage collection started16422026/10/08 12:59:46 INFO Aborted multipart uploads count=0 kept=016432026/10/08 12:59:46 WARN Force mode enabled - objects will be deleted immediately without grace period16442026/10/08 12:59:46 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=016452026/10/08 12:59:46 INFO Vacuumed table table=pending_closures16462026/10/08 12:59:46 INFO Vacuumed table table=pending_objects16472026/10/08 12:59:46 INFO Vacuumed table table=multipart_uploads16482026/10/08 12:59:46 INFO Vacuumed table table=closures16492026/10/08 12:59:46 INFO Vacuumed table table=objects1650--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (8.54s)1651=== CONT TestService_RequireScope_OIDC16522026/10/08 12:59:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53590/oidc16532026/10/08 12:59:46 INFO Received push request method=POST path=/api/pushes16542026/10/08 12:59:46 INFO Received complete push request method=POST path=/api/pushes/1/complete16552026/10/08 12:59:46 INFO Completed push id=1 objects=6 duration=40.016375ms1656--- PASS: TestPush_CompleteCommitsEveryRoot (8.96s)1657=== CONT TestService_AuthMiddleware_OIDC16582026/10/08 12:59:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53598/oidc1659--- PASS: TestReadRedirectUsesPublicS3URL (8.70s)1660=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1661--- PASS: TestDeleteClosuresRacingPins (13.21s)1662=== CONT TestService_AuthMiddleware_MTLSProxyHeader1663--- PASS: TestReadProxyRangeRequest (7.98s)1664=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1665=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16662026/10/08 12:59:47 INFO Received uploads request method=POST path=/1667=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16682026/10/08 12:59:47 INFO Received uploads request method=POST path=/1669=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16702026/10/08 12:59:47 INFO Received complete multipart upload request method=POST path=/1671=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16722026/10/08 12:59:48 INFO Received request for more parts method=POST path=/1673--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1674 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1675 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)1676 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1677 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1678=== CONT TestPendingClosureWriteTimeout/empty1679=== CONT TestProxyWriteTimeout/narinfo1680=== CONT TestPendingClosureWriteTimeout/670k_objects1681=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1682--- PASS: TestReadProxyConditionalGet (8.17s)1683=== CONT TestPendingClosureWriteTimeout/400_objects1684=== CONT TestProxyWriteTimeout/unknown_size1685=== CONT TestProxyWriteTimeout/10_GiB_nar1686=== CONT TestProxyWriteTimeout/1_GiB_nar1687--- PASS: TestProxyWriteTimeout (0.00s)1688 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1689 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1690 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1691 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1692=== CONT TestIsValidUploadKey/nix-cache-info1693=== CONT TestIsValidUploadKey/narinfo1694=== CONT TestIsValidUploadKey/realisation_plus_in_output1695=== CONT TestIsValidUploadKey/realisation1696=== CONT TestIsValidUploadKey/build_log_equals1697=== CONT TestIsValidUploadKey/build_log_question_mark1698=== CONT TestIsValidUploadKey/build_log_plus_in_name1699=== CONT TestIsValidUploadKey/build_log_home-manager_file1700=== CONT TestIsValidUploadKey/build_log1701=== CONT TestIsValidUploadKey/listing1702=== CONT TestIsValidUploadKey/nar_plain1703=== CONT TestIsValidUploadKey/nar_xz1704=== CONT TestIsValidUploadKey/nar_zst1705=== CONT TestIsValidUploadKey/traversal1706=== CONT TestIsValidUploadKey/unknown_type1707=== CONT TestIsValidUploadKey/empty_key1708=== CONT TestIsValidUploadKey/absolute1709=== CONT TestIsValidUploadKey/traversal_nar1710=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1711=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1712=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1713=== CONT TestIsValidUploadKey/index.html1714--- PASS: TestIsValidUploadKey (0.03s)1715 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1716 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1717 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log (0.00s)1724 --- PASS: TestIsValidUploadKey/listing (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1728 --- PASS: TestIsValidUploadKey/traversal (0.00s)1729 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1730 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1731 --- PASS: TestIsValidUploadKey/absolute (0.00s)1732 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1733 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1734 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1735 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1736 --- PASS: TestIsValidUploadKey/index.html (0.00s)1737=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17382026/10/08 12:59:48 INFO Received uploads request method=POST path=/1739=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17402026/10/08 12:59:48 INFO Received request for more parts method=POST path=/1741=== NAME TestPinProtectsFromGC1742 client_integration_test.go:840: Pin successfully protected closure from garbage collection1743=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17442026/10/08 12:59:48 INFO Received complete multipart upload request method=POST path=/1745--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)1746 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1747 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1748 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1749=== CONT TestServerTLSConfig/no_client_CA1750=== CONT TestServerTLSConfig/missing_CA_file1751=== CONT TestServerTLSConfig/not_a_PEM_file1752--- PASS: TestServerTLSConfig (0.01s)1753 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1754 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1755 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1756=== CONT TestPush_RejectsBadRequests/no_roots17572026/10/08 12:59:48 INFO Received push request method=POST path=/api/pushes1758=== CONT TestPush_RejectsBadRequests/bad_root17592026/10/08 12:59:48 INFO Received push request method=POST path=/api/pushes1760=== CONT TestPush_RejectsBadRequests/root_not_in_objects17612026/10/08 12:59:48 INFO Received push request method=POST path=/api/pushes1762=== CONT TestPush_RejectsBadRequests/no_objects17632026/10/08 12:59:48 INFO Received push request method=POST path=/api/pushes1764=== CONT TestGCEndsOnShutdown/before_the_run1765--- PASS: TestPush_RejectsBadRequests (2.64s)1766 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1767 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1768 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1769 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1770--- PASS: TestPinProtectsFromGC (13.33s)1771=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1772--- PASS: TestReadRedirectKeepsNarinfoProxied (8.27s)1773=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1774--- PASS: TestReadRedirectNar (7.63s)1775=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1776--- PASS: TestReadProxyHead (7.37s)1777=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1778--- PASS: TestReadProxyDisabled (7.53s)1779=== CONT TestResolveDBConnectionString/flag_wins1780=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1781=== CONT TestResolveDBConnectionString/nothing_configured1782=== CONT TestResolveDBConnectionString/missing_file_is_an_error1783=== CONT TestResolveDBConnectionString/file_when_flag_empty1784=== CONT TestIsValidCachePath/narinfo1785=== CONT TestIsValidCachePath/index.html1786=== CONT TestIsValidCachePath/short_hash1787=== CONT TestIsValidCachePath/wrong_extension1788=== CONT TestIsValidCachePath/leading_slash1789=== CONT TestIsValidCachePath/empty1790=== CONT TestIsValidCachePath/traversal_in_middle1791=== CONT TestIsValidCachePath/invalid_char_e1792=== CONT TestIsValidCachePath/traversal_parent1793=== CONT TestIsValidCachePath/random_path1794=== CONT TestIsValidCachePath/nar_uncompressed1795=== CONT TestIsValidCachePath/invalid_char_u1796=== CONT TestIsValidCachePath/nix-cache-info1797=== CONT TestIsValidCachePath/ls1798=== CONT TestIsValidCachePath/log1799=== CONT TestIsValidCachePath/realisation1800=== CONT TestIsValidCachePath/nar_xz1801=== CONT TestIsValidCachePath/nar_zst1802=== CONT TestIsValidCachePath/nar_bz21803=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1804--- PASS: TestIsValidCachePath (0.00s)1805 --- PASS: TestIsValidCachePath/narinfo (0.00s)1806 --- PASS: TestIsValidCachePath/index.html (0.00s)1807 --- PASS: TestIsValidCachePath/short_hash (0.00s)1808 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1809 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1810 --- PASS: TestIsValidCachePath/empty (0.00s)1811 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1812 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1813 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1814 --- PASS: TestIsValidCachePath/random_path (0.00s)1815 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1816 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1817 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1818 --- PASS: TestIsValidCachePath/ls (0.00s)1819 --- PASS: TestIsValidCachePath/log (0.00s)1820 --- PASS: TestIsValidCachePath/realisation (0.00s)1821 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1822 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1823 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1824 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1825=== CONT TestParseSingleRange/none1826=== CONT TestParseSingleRange/open-ended1827=== CONT TestParseSingleRange/start_far_past_EOF1828=== CONT TestParseSingleRange/start_past_EOF1829--- PASS: TestResolveDBConnectionString (0.04s)1830 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1831 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1832 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1833 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1834 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1835=== CONT TestParseSingleRange/single_byte1836=== CONT TestParseSingleRange/suffix_exceeds_size1837=== CONT TestParseSingleRange/suffix1838=== CONT TestParseSingleRange/end_clamped_to_size1839=== CONT TestParseSingleRange/malformed_both_empty1840=== CONT TestParseSingleRange/closed1841=== CONT TestParseSingleRange/malformed_end_before_start1842=== CONT TestParseSingleRange/multi-range_ignored1843=== CONT TestParseSingleRange/malformed_no_dash1844=== CONT TestParseSingleRange/unknown_unit1845--- PASS: TestParseSingleRange (0.01s)1846 --- PASS: TestParseSingleRange/none (0.00s)1847 --- PASS: TestParseSingleRange/open-ended (0.00s)1848 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1849 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1850 --- PASS: TestParseSingleRange/single_byte (0.00s)1851 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1852 --- PASS: TestParseSingleRange/suffix (0.00s)1853 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1854 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1855 --- PASS: TestParseSingleRange/closed (0.00s)1856 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1857 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1858 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1859 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1860=== CONT TestClientErrorHandling/InvalidStorePath1861--- PASS: TestReadProxyInvalidPath (6.25s)1862=== CONT TestClientErrorHandling/ServerNotAvailable18632026/10/08 12:59:50 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/present1864--- PASS: TestReadProxyNarStreaming (6.21s)1865=== CONT TestClientErrorHandling/InvalidAuthToken18662026/10/08 12:59:50 WARN Request failed, retrying attempt=2 backoff=211.345215ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18672026/10/08 12:59:50 WARN Request failed, retrying attempt=3 backoff=371.386209ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1868--- PASS: TestReadProxy404 (6.64s)1869=== CONT TestCacheConfigHandler/full_config,_no_issuer1870=== CONT TestCacheConfigHandler/no_signing_keys1871=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1872=== CONT TestCacheConfigHandler/no_cache_url_configured1873--- PASS: TestCacheConfigHandler (0.01s)1874 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1875 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1876 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1877 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)18782026-10-08 12:59:50.878 UTC [45017] LOG: checkpoint starting: wal18792026/10/08 12:59:50 WARN Request failed, retrying attempt=4 backoff=797.799142ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1880--- PASS: TestReadProxyContentNegotiation (6.32s)18812026/10/08 12:59:51 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1882--- PASS: TestReadProxyNarinfo (6.50s)1883--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.83s)18842026/10/08 12:59:51 WARN Request failed, retrying attempt=5 backoff=1.754302468s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1885--- PASS: TestService_ReadScope_PublicByDefault (6.45s)1886=== NAME TestClientIntegration1887 client_integration_test.go:286: Created store path: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientIntegration1525750824/002/store/p8v5k9dyk541akdpffqqbph6mabdwsya-test-file.txt1888=== NAME TestClientCADerivations1889 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientCADerivations2658373148/001/store/k89ayknhp4ynxk3nxrc0q21vnxggkf7a-ca-test18902026/10/08 12:59:52 INFO Received push request method=POST path=/api/pushes1891--- PASS: TestCacheStatsHandler (6.35s)18922026/10/08 12:59:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18932026/10/08 12:59:52 INFO Uploading p8v5k9dyk541akdpffqqbph6mabdwsya-test-file.txt (152B)1894=== NAME TestClientCADerivations1895 client_ca_test.go:139: Found 1 dependencies (including self)18962026/10/08 12:59:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18972026/10/08 12:59:52 WARN Failed to register uploaded object key=p8v5k9dyk541akdpffqqbph6mabdwsya.ls error="server returned 404: 404 page not found\n"18982026/10/08 12:59:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18992026/10/08 12:59:52 INFO Signed narinfos id=1 count=119002026/10/08 12:59:52 INFO Uploading 1 narinfos19012026/10/08 12:59:52 INFO Received complete push request method=POST path=/api/pushes/1/complete19022026/10/08 12:59:52 WARN Failed to register uploaded object key=p8v5k9dyk541akdpffqqbph6mabdwsya.narinfo error="server returned 404: 404 page not found\n"19032026/10/08 12:59:52 INFO Completed push id=1 objects=3 duration=5.319959ms19042026/10/08 12:59:52 INFO Upload complete. (98ms)1905--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.10s)19062026/10/08 12:59:52 INFO All 1 paths already cached1907=== NAME TestClientIntegration1908 client_integration_test.go:312: Retrieved narinfo from S3:1909 StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientIntegration1525750824/002/store/p8v5k9dyk541akdpffqqbph6mabdwsya-test-file.txt1910 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1911 Compression: zstd1912 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11913 NarSize: 1521914 References: 1915 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11916 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1917 client_integration_test.go:313: Decompressed .ls content (64 bytes):1918 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1919 client_integration_test.go:316: Testing garbage collection...19202026/10/08 12:59:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures19212026/10/08 12:59:52 INFO Garbage collection started19222026/10/08 12:59:52 INFO Aborted multipart uploads count=0 kept=019232026/10/08 12:59:52 INFO Received push request method=POST path=/api/pushes19242026/10/08 12:59:52 WARN Force mode enabled - objects will be deleted immediately without grace period19252026/10/08 12:59:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19262026/10/08 12:59:52 INFO Uploading k89ayknhp4ynxk3nxrc0q21vnxggkf7a-ca-test (144B)19272026/10/08 12:59:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19282026/10/08 12:59:52 WARN Failed to register uploaded object key=k89ayknhp4ynxk3nxrc0q21vnxggkf7a.ls error="server returned 404: 404 page not found\n"19292026/10/08 12:59:52 WARN Failed to register uploaded object key=log/kkffagnzqplgrm5pq049l4nzk6gyzfhs-ca-test.drv error="server returned 404: 404 page not found\n"19302026/10/08 12:59:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19312026/10/08 12:59:52 INFO Signed narinfos id=1 count=11932--- PASS: TestService_ReadAuthMiddleware (6.40s)19332026/10/08 12:59:52 INFO Uploading 1 narinfos19342026/10/08 12:59:52 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=019352026/10/08 12:59:52 INFO Received complete push request method=POST path=/api/pushes/1/complete19362026/10/08 12:59:52 WARN Failed to register uploaded object key=k89ayknhp4ynxk3nxrc0q21vnxggkf7a.narinfo error="server returned 404: 404 page not found\n"19372026/10/08 12:59:52 INFO Vacuumed table table=pending_closures19382026/10/08 12:59:52 INFO Completed push id=1 objects=4 duration=15.601ms19392026/10/08 12:59:52 INFO Vacuumed table table=pending_objects19402026/10/08 12:59:52 INFO Upload complete. (160ms)19412026/10/08 12:59:52 INFO Vacuumed table table=multipart_uploads1942=== NAME TestClientCADerivations1943 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientCADerivations2658373148/001/store/k89ayknhp4ynxk3nxrc0q21vnxggkf7a-ca-test1944 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1945 Compression: zstd1946 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1947 NarSize: 1441948 References: 1949 Deriver: /private/var/tb/8/scratch/f058402f878f26dd/build/TestClientCADerivations2658373148/001/store/kkffagnzqplgrm5pq049l4nzk6gyzfhs-ca-test.drv1950 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1951 client_ca_test.go:185: Checking for realisation files in S3...1952 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1953 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19542026/10/08 12:59:52 INFO Vacuumed table table=closures19552026/10/08 12:59:52 INFO Vacuumed table table=objects1956 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket84?endpoint=http://localhost:53104®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/f058402f878f26dd/build/TestClientCADerivations2658373148/001/store'1957 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11958--- PASS: TestClientCADerivations (7.14s)1959=== RUN TestService_RequireScope_OIDC/builder_may_write1960=== PAUSE TestService_RequireScope_OIDC/builder_may_write1961=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1962=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1963=== RUN TestService_RequireScope_OIDC/ops_may_admin1964=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1965=== RUN TestService_RequireScope_OIDC/ops_may_not_write1966=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1967=== RUN TestService_RequireScope_OIDC/reader_may_not_write1968=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1969=== RUN TestService_RequireScope_OIDC/static_token_may_admin1970=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1971=== RUN TestService_RequireScope_OIDC/static_token_may_write1972=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1973=== RUN TestService_RequireScope_OIDC/reader_may_read1974=== PAUSE TestService_RequireScope_OIDC/reader_may_read1975=== RUN TestService_RequireScope_OIDC/writer_implies_read1976=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1977=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1978=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1979=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1980=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1981=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1982=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1983=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1984=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1985=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1986=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1987=== CONT TestService_RequireScope_OIDC/builder_may_write1988=== CONT TestService_RequireScope_OIDC/reader_may_read1989=== CONT TestService_RequireScope_OIDC/reader_may_not_write1990=== CONT TestService_RequireScope_OIDC/static_token_may_write1991=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1992=== CONT TestService_RequireScope_OIDC/static_token_may_admin1993=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1994=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1995=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19962026/10/08 12:59:52 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]1997=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1998=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1999=== CONT TestService_RequireScope_OIDC/ops_may_not_write2000=== CONT TestService_RequireScope_OIDC/ops_may_admin2001=== CONT TestService_RequireScope_OIDC/writer_implies_read2002--- PASS: TestService_RequireScope_OIDC (6.31s)2003 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2006 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2010 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2011 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.01s)2012 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2013 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2014 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2015 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2016 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2017=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2018=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2019=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2020=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2021=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2022=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2023=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2024=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2025=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2026=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20272026/10/08 12:59:53 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]2028=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2029=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20302026/10/08 12:59:53 WARN Authentication failed token_preview=eyJhbGciOi...SdOv41WhzA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2031--- PASS: TestService_AuthMiddleware_OIDC (6.07s)2032 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2033 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2034 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2035 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2036--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.13s)20372026/10/08 12:59:53 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-config20382026/10/08 12:59:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20392026/10/08 12:59:53 WARN mTLS auth: bound subjects configured but subject DN unavailable20402026/10/08 12:59:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2041--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.89s)20422026/10/08 12:59:53 WARN Request failed, retrying attempt=2 backoff=197.172727ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2043--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2044 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (8.75s)2045 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.57s)20462026/10/08 12:59:53 INFO Received uploads request method=POST path=/api/pending_closures20472026/10/08 12:59:53 WARN Request failed, retrying attempt=3 backoff=374.314167ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20482026/10/08 12:59:54 INFO Aborted multipart uploads count=0 kept=020492026/10/08 12:59:54 WARN Force mode enabled - objects will be deleted immediately without grace period20502026-10-08 12:59:54.173 UTC [45685] ERROR: canceling statement due to user request20512026-10-08 12:59:54.173 UTC [45685] STATEMENT: -- name: MarkStaleObjects :execrows2052 WITH RECURSIVE ct AS (2053 SELECT timezone('UTC', now()) AS now2054 ),2055 closure_reach AS (2056 -- Start with all closure keys2057 SELECT o.key, o.refs2058 FROM objects o2059 INNER JOIN closures c ON o.key = c.key2060 UNION2061 -- Recursively add all referenced objects2062 SELECT o.key, o.refs2063 FROM objects o2064 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2065 ),2066 reachable_objects AS (2067 SELECT DISTINCT key FROM closure_reach2068 ),2069 stale_objects AS (2070 SELECT o.key2071 FROM objects AS o, ct2072 WHERE2073 NOT EXISTS (2074 SELECT 12075 FROM reachable_objects ro2076 WHERE ro.key = o.key2077 )2078 AND NOT EXISTS (2079 SELECT 12080 FROM pending_objects AS po2081 WHERE po.key = o.key2082 )2083 AND o.deleted_at IS NULL -- Only mark fresh objects2084 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2085 FOR UPDATE2086 )2087 UPDATE objects2088 SET2089 deleted_at = ct.now,2090 first_deleted_at = COALESCE(first_deleted_at, ct.now)2091 FROM stale_objects, ct2092 WHERE objects.key = stale_objects.key2093 20942026/10/08 12:59:54 WARN Request failed, retrying attempt=4 backoff=732.829579ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2095--- PASS: TestPendingClosureWriteTimeout (0.00s)2096 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2097 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2098 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2099 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.65s)21002026/10/08 12:59:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02101=== NAME TestClientIntegration2102 client_integration_test.go:323: Objects in database after GC:2103 client_integration_test.go:323: Successfully deleted all objects with GC --force21042026/10/08 12:59:54 INFO Aborted multipart uploads count=0 kept=021052026/10/08 12:59:54 WARN Force mode enabled - objects will be deleted immediately without grace period21062026/10/08 12:59:54 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53104/bucket96/?delete=\": context canceled"2107--- PASS: TestGCEndsOnShutdown (0.00s)2108 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.54s)2109 --- PASS: TestGCEndsOnShutdown/before_the_run (5.88s)2110 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.17s)2111--- PASS: TestClientIntegration (9.16s)21122026/10/08 12:59:54 INFO Received uploads request method=POST path=/api/pending_closures21132026/10/08 12:59:54 INFO Aborted multipart uploads count=0 kept=021142026/10/08 12:59:55 WARN Force mode enabled - objects will be deleted immediately without grace period21152026/10/08 12:59:55 WARN Request failed, retrying attempt=5 backoff=1.4456844s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/08 12:59:55 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=021172026/10/08 12:59:55 INFO Vacuumed table table=pending_closures21182026/10/08 12:59:55 INFO Vacuumed table table=pending_objects21192026/10/08 12:59:55 INFO Vacuumed table table=multipart_uploads21202026/10/08 12:59:55 INFO Vacuumed table table=closures21212026/10/08 12:59:55 INFO Vacuumed table table=objects21222026/10/08 12:59:55 INFO Received uploads request method=POST path=/api/pending_closures21232026/10/08 12:59:55 INFO Aborted multipart uploads count=0 kept=021242026/10/08 12:59:55 WARN Force mode enabled - objects will be deleted immediately without grace period21252026/10/08 12:59:55 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=021262026/10/08 12:59:55 INFO Vacuumed table table=pending_closures21272026/10/08 12:59:55 INFO Vacuumed table table=pending_objects21282026/10/08 12:59:55 INFO Vacuumed table table=multipart_uploads21292026/10/08 12:59:55 INFO Vacuumed table table=closures21302026/10/08 12:59:55 INFO Vacuumed table table=objects2131--- PASS: TestForceGCDuringPushOffersSweptObject (0.03s)2132 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.23s)2133 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.99s)21342026/10/08 12:59:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21352026/10/08 12:59:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21362026/10/08 12:59:56 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"21372026/10/08 12:59:56 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-config21382026/10/08 12:59:56 WARN Request failed, retrying attempt=2 backoff=198.630803ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21392026/10/08 12:59:56 WARN Request failed, retrying attempt=3 backoff=360.214949ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21402026/10/08 12:59:57 WARN Request failed, retrying attempt=4 backoff=788.353878ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/08 12:59:57 WARN Request failed, retrying attempt=5 backoff=1.51991643s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/08 12:59:59 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_closures21432026/10/08 12:59:59 WARN Request failed, retrying attempt=2 backoff=202.974908ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21442026/10/08 12:59:59 WARN Request failed, retrying attempt=3 backoff=415.686687ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21452026/10/08 13:00:00 WARN Request failed, retrying attempt=4 backoff=729.794154ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/08 13:00:00 WARN Request failed, retrying attempt=5 backoff=1.673739977s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2147--- PASS: TestClientErrorHandling (0.00s)2148 --- PASS: TestClientErrorHandling/InvalidStorePath (5.82s)2149 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.56s)2150 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.68s)2151PASS2152{"timestamp":"2026-10-08T13:00:02.646764Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53348","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}21532026-10-08 13:00:02.862 UTC [45012] LOG: received smart shutdown request21542026-10-08 13:00:02.863 UTC [45012] LOG: background worker "logical replication launcher" (PID 45022) exited with exit code 121552026-10-08 13:00:04.190 UTC [45017] LOG: checkpoint complete: wrote 10957 buffers (66.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.535 s, sync=0.678 s, total=13.313 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=533150 kB, estimate=533150 kB; lsn=0/22824598, redo lsn=0/22034A9821562026-10-08 13:00:04.190 UTC [45017] LOG: shutting down21572026-10-08 13:00:04.190 UTC [45017] LOG: checkpoint starting: shutdown immediate21582026-10-08 13:00:04.290 UTC [45017] LOG: checkpoint complete: wrote 1352 buffers (8.3%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.077 s, sync=0.022 s, total=0.100 s; sync files=490, longest=0.004 s, average=0.001 s; distance=8126 kB, estimate=480648 kB; lsn=0/22824610, redo lsn=0/2282461021592026-10-08 13:00:04.296 UTC [45012] LOG: database system is shut down2160Running OIDC tests...2161=== RUN TestAudienceForIssuer2162=== PAUSE TestAudienceForIssuer2163=== RUN TestGlobMatch2164=== PAUSE TestGlobMatch2165=== RUN TestValidateToken_ValidToken2166=== PAUSE TestValidateToken_ValidToken2167=== RUN TestValidateToken_WrongAudience2168=== PAUSE TestValidateToken_WrongAudience2169=== RUN TestValidateToken_Expired2170=== PAUSE TestValidateToken_Expired2171=== RUN TestValidateToken_BoundClaimsMismatch2172=== PAUSE TestValidateToken_BoundClaimsMismatch2173=== RUN TestValidateToken_BoundSubjectMismatch2174=== PAUSE TestValidateToken_BoundSubjectMismatch2175=== RUN TestValidateToken_MultipleProviders2176=== PAUSE TestValidateToken_MultipleProviders2177=== RUN TestValidateToken_NoMatchingProvider2178=== PAUSE TestValidateToken_NoMatchingProvider2179=== RUN TestValidateToken_KubernetesServiceAccount2180=== PAUSE TestValidateToken_KubernetesServiceAccount2181=== RUN TestNewValidator_KubernetesRequiresCA2182=== PAUSE TestNewValidator_KubernetesRequiresCA2183=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2184=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2185=== RUN TestPins_ReservedForMatchingRule2186=== PAUSE TestPins_ReservedForMatchingRule2187=== RUN TestPins_TopLevelShorthand2188=== PAUSE TestPins_TopLevelShorthand2189=== RUN TestPins_ConfigValidation2190=== PAUSE TestPins_ConfigValidation2191=== RUN TestScopes_LegacyProviderDefaultsToWrite2192=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2193=== RUN TestScopes_Rules2194=== PAUSE TestScopes_Rules2195=== RUN TestScopes_ConfigValidation2196=== PAUSE TestScopes_ConfigValidation2197=== CONT TestAudienceForIssuer2198--- PASS: TestAudienceForIssuer (0.00s)2199=== CONT TestValidateToken_Expired2200=== CONT TestValidateToken_BoundClaimsMismatch2201=== CONT TestValidateToken_BoundSubjectMismatch2202=== CONT TestValidateToken_MultipleProviders2203=== CONT TestValidateToken_NoMatchingProvider2204=== CONT TestValidateToken_ValidToken2205=== CONT TestValidateToken_WrongAudience2206=== CONT TestGlobMatch2207=== RUN TestGlobMatch/foo_foo2208=== PAUSE TestGlobMatch/foo_foo2209=== RUN TestGlobMatch/foo_bar2210=== PAUSE TestGlobMatch/foo_bar2211=== RUN TestGlobMatch/*_2212=== PAUSE TestGlobMatch/*_2213=== RUN TestGlobMatch/*_anything2214=== PAUSE TestGlobMatch/*_anything2215=== RUN TestGlobMatch/foo*_foo2216=== PAUSE TestGlobMatch/foo*_foo2217=== RUN TestGlobMatch/foo*_foobar2218=== PAUSE TestGlobMatch/foo*_foobar2219=== RUN TestGlobMatch/foo*_bar2220=== PAUSE TestGlobMatch/foo*_bar2221=== RUN TestGlobMatch/*bar_bar2222=== PAUSE TestGlobMatch/*bar_bar2223=== RUN TestGlobMatch/*bar_foobar2224=== PAUSE TestGlobMatch/*bar_foobar2225=== RUN TestGlobMatch/*bar_foo2226=== PAUSE TestGlobMatch/*bar_foo2227=== RUN TestGlobMatch/foo*bar_foobar2228=== PAUSE TestGlobMatch/foo*bar_foobar2229=== RUN TestGlobMatch/foo*bar_foo123bar2230=== PAUSE TestGlobMatch/foo*bar_foo123bar2231=== RUN TestGlobMatch/foo*bar_foobarbaz2232=== PAUSE TestGlobMatch/foo*bar_foobarbaz2233=== RUN TestGlobMatch/*/*_foo/bar2234=== PAUSE TestGlobMatch/*/*_foo/bar2235=== RUN TestGlobMatch/*/*_foo2236=== PAUSE TestGlobMatch/*/*_foo2237=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2238=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2239=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02240=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02241=== RUN TestGlobMatch/refs/*/main_refs/heads/main2242=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2243=== RUN TestGlobMatch/fo?_foo2244=== PAUSE TestGlobMatch/fo?_foo2245=== RUN TestGlobMatch/fo?_fo2246=== PAUSE TestGlobMatch/fo?_fo2247=== RUN TestGlobMatch/fo?_fooo2248=== PAUSE TestGlobMatch/fo?_fooo2249=== RUN TestGlobMatch/?oo_foo2250=== PAUSE TestGlobMatch/?oo_foo2251=== RUN TestGlobMatch/?oo_boo2252=== PAUSE TestGlobMatch/?oo_boo2253=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2254=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2255=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2256=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2257=== CONT TestGlobMatch/foo_foo2258=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2259=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2260=== CONT TestGlobMatch/?oo_boo2261=== CONT TestGlobMatch/?oo_foo2262=== CONT TestGlobMatch/fo?_fooo2263=== CONT TestGlobMatch/fo?_fo2264=== CONT TestGlobMatch/fo?_foo2265=== CONT TestGlobMatch/refs/*/main_refs/heads/main2266=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02267=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2268=== CONT TestGlobMatch/*/*_foo2269=== CONT TestGlobMatch/*/*_foo/bar2270=== CONT TestGlobMatch/foo*bar_foobarbaz2271=== CONT TestGlobMatch/foo*bar_foo123bar2272=== CONT TestGlobMatch/foo*bar_foobar2273=== CONT TestGlobMatch/*bar_foo2274=== CONT TestGlobMatch/*bar_foobar2275=== CONT TestGlobMatch/*bar_bar2276=== CONT TestGlobMatch/foo*_bar2277=== CONT TestGlobMatch/foo*_foobar2278=== CONT TestGlobMatch/foo*_foo2279=== CONT TestGlobMatch/*_anything2280=== CONT TestGlobMatch/*_2281=== CONT TestGlobMatch/foo_bar2282--- PASS: TestGlobMatch (0.00s)2283 --- PASS: TestGlobMatch/foo_foo (0.00s)2284 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2285 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2286 --- PASS: TestGlobMatch/?oo_boo (0.00s)2287 --- PASS: TestGlobMatch/?oo_foo (0.00s)2288 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2289 --- PASS: TestGlobMatch/fo?_fo (0.00s)2290 --- PASS: TestGlobMatch/fo?_foo (0.00s)2291 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2292 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2293 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2294 --- PASS: TestGlobMatch/*/*_foo (0.00s)2295 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2296 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2297 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2298 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2299 --- PASS: TestGlobMatch/*bar_foo (0.00s)2300 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2301 --- PASS: TestGlobMatch/*bar_bar (0.00s)2302 --- PASS: TestGlobMatch/foo*_bar (0.00s)2303 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2304 --- PASS: TestGlobMatch/foo*_foo (0.00s)2305 --- PASS: TestGlobMatch/*_anything (0.00s)2306 --- PASS: TestGlobMatch/*_ (0.00s)2307 --- PASS: TestGlobMatch/foo_bar (0.00s)2308=== CONT TestValidateToken_KubernetesServiceAccount2309=== CONT TestScopes_ConfigValidation2310=== CONT TestScopes_Rules2311=== CONT TestScopes_LegacyProviderDefaultsToWrite2312--- PASS: TestScopes_ConfigValidation (0.00s)2313=== CONT TestPins_ConfigValidation2314=== CONT TestPins_TopLevelShorthand2315--- PASS: TestPins_ConfigValidation (0.00s)2316=== CONT TestPins_ReservedForMatchingRule2317=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2318=== CONT TestNewValidator_KubernetesRequiresCA23192026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53777/oidc2320--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)23212026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53779/oidc23222026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53781/oidc2323--- PASS: TestValidateToken_Expired (0.09s)2324--- PASS: TestScopes_Rules (0.08s)23252026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53785/oidc23262026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53788/oidc2327--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2328--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)23292026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53790/oidc23302026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53792/oidc23312026/10/08 13:00:06 http: TLS handshake error from 127.0.0.1:53786: remote error: tls: bad certificate2332--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)2333--- PASS: TestPins_ReservedForMatchingRule (0.10s)23342026/10/08 13:00:06 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:537942335--- PASS: TestPins_TopLevelShorthand (0.10s)23362026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53797/oidc2337--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)2338--- PASS: TestValidateToken_WrongAudience (0.11s)23392026/10/08 13:00:06 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232340--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)23412026/10/08 13:00:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53803/oidc2342--- PASS: TestValidateToken_ValidToken (0.13s)23432026/10/08 13:00:06 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53783/oidc23442026/10/08 13:00:06 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:53805/oidc2345--- PASS: TestValidateToken_MultipleProviders (0.16s)23462026/10/08 13:00:06 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53800/oidc2347--- PASS: TestValidateToken_NoMatchingProvider (0.19s)2348PASS2349Running hook tests...2350=== RUN TestSendPathsEmpty2351=== PAUSE TestSendPathsEmpty2352=== RUN TestQueueEnqueueAndFetch2353=== PAUSE TestQueueEnqueueAndFetch2354=== RUN TestQueueDeduplication2355=== PAUSE TestQueueDeduplication2356=== RUN TestQueueRemove2357=== PAUSE TestQueueRemove2358=== RUN TestQueueFetchBatchLimit2359=== PAUSE TestQueueFetchBatchLimit2360=== RUN TestQueueRetryMovesToBack2361=== PAUSE TestQueueRetryMovesToBack2362=== RUN TestQueueFetchRemoveLifecycle2363=== PAUSE TestQueueFetchRemoveLifecycle2364=== RUN TestQueueConcurrentWriters2365=== PAUSE TestQueueConcurrentWriters2366=== RUN TestQueueRemoveLargeClosure2367=== PAUSE TestQueueRemoveLargeClosure2368=== RUN TestServerClientIntegration2369--- PASS: TestServerClientIntegration (0.00s)2370=== RUN TestServerQueueError23712026/10/08 13:00:06 ERROR Failed to queue paths error="permission denied" count=12372--- PASS: TestServerQueueError (0.00s)2373=== RUN TestGetListenerSocketActivation2374 server_test.go:146: systemd socket activation does not exist on darwin2375--- SKIP: TestGetListenerSocketActivation (0.00s)2376=== RUN TestDrainIsolatesPoisonPath2377=== PAUSE TestDrainIsolatesPoisonPath2378=== RUN TestRunNotBlockedByPoisonHead2379=== PAUSE TestRunNotBlockedByPoisonHead2380=== RUN TestDrainGivesUpWhenServerDown2381=== PAUSE TestDrainGivesUpWhenServerDown2382=== RUN TestFailedPathPrunedByLaterClosure2383=== PAUSE TestFailedPathPrunedByLaterClosure2384=== RUN TestWorkerUploadsAndRemoves2385=== PAUSE TestWorkerUploadsAndRemoves2386=== RUN TestWorkerSkipsGCdPaths2387=== PAUSE TestWorkerSkipsGCdPaths2388=== RUN TestWorkerPrunesClosureDeps2389=== PAUSE TestWorkerPrunesClosureDeps2390=== RUN TestDrainTimeout2391=== PAUSE TestDrainTimeout2392=== CONT TestSendPathsEmpty2393--- PASS: TestSendPathsEmpty (0.00s)2394=== CONT TestDrainTimeout2395=== CONT TestQueueRemoveLargeClosure2396=== CONT TestQueueConcurrentWriters2397=== CONT TestQueueFetchRemoveLifecycle2398=== CONT TestQueueRetryMovesToBack2399=== CONT TestQueueFetchBatchLimit2400=== CONT TestQueueRemove2401=== CONT TestQueueDeduplication2402=== CONT TestQueueEnqueueAndFetch2403=== CONT TestDrainIsolatesPoisonPath2404=== CONT TestWorkerUploadsAndRemoves2405=== CONT TestWorkerPrunesClosureDeps2406=== CONT TestWorkerSkipsGCdPaths2407=== CONT TestDrainGivesUpWhenServerDown2408=== CONT TestFailedPathPrunedByLaterClosure2409=== CONT TestRunNotBlockedByPoisonHead2410--- PASS: TestQueueFetchBatchLimit (0.01s)24112026/10/08 13:00:06 INFO Upload queue status pending=224122026/10/08 13:00:06 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestWorkerSkipsGCdPaths798883759/002/nonexistent24132026/10/08 13:00:06 INFO Uploading batch count=224142026/10/08 13:00:06 INFO Uploading batch count=124152026/10/08 13:00:06 INFO Upload queue status pending=224162026/10/08 13:00:06 INFO Uploading batch count=12417--- PASS: TestQueueRetryMovesToBack (0.01s)24182026/10/08 13:00:06 INFO Uploading batch count=424192026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=42420--- PASS: TestQueueDeduplication (0.01s)24212026/10/08 13:00:06 INFO Upload queue status pending=224222026/10/08 13:00:06 INFO Uploading batch count=124232026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=124242026/10/08 13:00:06 INFO Uploading batch count=22425--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24262026/10/08 13:00:06 INFO Uploading batch count=224272026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=224282026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/a24292026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainIsolatesPoisonPath836598520/002/bbb24302026/10/08 13:00:06 INFO Uploading batch count=124312026/10/08 13:00:06 INFO Upload queue status pending=324322026/10/08 13:00:06 INFO Uploading batch count=124332026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=12434--- PASS: TestQueueRemove (0.02s)24352026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/b24362026/10/08 13:00:06 INFO Uploading batch count=12437--- PASS: TestQueueEnqueueAndFetch (0.01s)24382026/10/08 13:00:06 INFO Uploading batch count=224392026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=224402026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/c24412026/10/08 13:00:06 INFO Uploading batch count=124422026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=124432026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/d24442026/10/08 13:00:06 INFO Uploading batch count=124452026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=124462026/10/08 13:00:06 INFO Uploading batch count=224472026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=224482026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/e24492026/10/08 13:00:06 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/f058402f878f26dd/build/TestDrainGivesUpWhenServerDown883051586/002/f24502026/10/08 13:00:06 INFO Uploading batch count=124512026/10/08 13:00:06 ERROR Upload failed error="upload failed" count=124522026/10/08 13:00:06 ERROR Drain finished with paths left in queue remaining=1024532026/10/08 13:00:06 ERROR Drain finished with paths left in queue remaining=12454--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2455--- PASS: TestDrainIsolatesPoisonPath (0.02s)2456--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2457--- PASS: TestWorkerSkipsGCdPaths (0.03s)2458--- PASS: TestWorkerPrunesClosureDeps (0.03s)2459--- PASS: TestWorkerUploadsAndRemoves (0.03s)2460--- PASS: TestQueueRemoveLargeClosure (0.05s)2461--- PASS: TestQueueConcurrentWriters (0.16s)24622026/10/08 13:00:06 ERROR Upload failed error="context deadline exceeded" count=224632026/10/08 13:00:06 ERROR Drain finished with paths left in queue remaining=42464--- PASS: TestDrainTimeout (0.22s)24652026/10/08 13:00:07 INFO Uploading batch count=124662026/10/08 13:00:07 INFO Uploading batch count=124672026/10/08 13:00:07 INFO Uploading batch count=124682026/10/08 13:00:07 ERROR Upload failed error="upload failed" count=124692026/10/08 13:00:07 INFO Uploading batch count=124702026/10/08 13:00:07 ERROR Upload failed error="upload failed" count=124712026/10/08 13:00:07 INFO Uploading batch count=124722026/10/08 13:00:07 ERROR Upload failed error="upload failed" count=124732026/10/08 13:00:07 INFO Uploading batch count=124742026/10/08 13:00:07 ERROR Upload failed error="upload failed" count=124752026/10/08 13:00:07 ERROR Drain finished with paths left in queue remaining=12476--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2477PASS2478Running signing tests...2479=== RUN TestExternalSigner2480=== PAUSE TestExternalSigner2481=== RUN TestExternalSignerWrongPublicKey2482=== PAUSE TestExternalSignerWrongPublicKey2483=== RUN TestExternalSignerErrors2484=== PAUSE TestExternalSignerErrors2485=== RUN TestExternalSignerRestartsAfterCrash2486=== PAUSE TestExternalSignerRestartsAfterCrash2487=== RUN TestExternalSignerProgramErrorKeepsProcess2488=== PAUSE TestExternalSignerProgramErrorKeepsProcess2489=== RUN TestExternalSignerClose2490=== PAUSE TestExternalSignerClose2491=== RUN TestExternalSignerRejectsInvalidPublicKey2492=== PAUSE TestExternalSignerRejectsInvalidPublicKey2493=== RUN TestExternalSignerCancellation2494=== PAUSE TestExternalSignerCancellation2495=== RUN TestGenerateFingerprint2496=== PAUSE TestGenerateFingerprint2497=== RUN TestParseSigningKey2498=== PAUSE TestParseSigningKey2499=== RUN TestSign2500=== PAUSE TestSign2501=== RUN TestSignBatch2502=== PAUSE TestSignBatch2503=== RUN TestNilKeyPublicKey2504=== PAUSE TestNilKeyPublicKey2505=== RUN TestSignErrors2506=== PAUSE TestSignErrors2507=== CONT TestExternalSigner2508=== CONT TestSignBatch2509=== CONT TestExternalSignerCancellation2510=== CONT TestExternalSignerProgramErrorKeepsProcess2511=== CONT TestSign2512=== CONT TestParseSigningKey2513=== RUN TestParseSigningKey/valid_32-byte_key2514=== PAUSE TestParseSigningKey/valid_32-byte_key2515=== CONT TestGenerateFingerprint2516=== RUN TestGenerateFingerprint/basic_with_references2517=== CONT TestExternalSignerErrors2518=== CONT TestExternalSignerRestartsAfterCrash2519=== CONT TestExternalSignerRejectsInvalidPublicKey2520=== RUN TestExternalSignerRejectsInvalidPublicKey/#002521=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002522=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2523=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2524=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2525=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2526=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2527=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2528=== CONT TestSignErrors2529=== CONT TestNilKeyPublicKey2530=== CONT TestExternalSignerWrongPublicKey2531=== CONT TestExternalSignerClose2532=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2533=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2534=== RUN TestParseSigningKey/no_colon2535=== PAUSE TestParseSigningKey/no_colon2536=== RUN TestParseSigningKey/empty_name2537=== PAUSE TestParseSigningKey/empty_name2538=== RUN TestParseSigningKey/invalid_base642539=== PAUSE TestParseSigningKey/invalid_base642540=== RUN TestParseSigningKey/wrong_length2541=== PAUSE TestParseSigningKey/wrong_length2542=== CONT TestParseSigningKey/valid_32-byte_key2543=== PAUSE TestGenerateFingerprint/basic_with_references2544=== RUN TestGenerateFingerprint/no_references2545=== CONT TestParseSigningKey/empty_name2546=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2547=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2548=== CONT TestExternalSignerRejectsInvalidPublicKey/#002549=== CONT TestParseSigningKey/wrong_length2550=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2551--- PASS: TestNilKeyPublicKey (0.00s)2552=== CONT TestParseSigningKey/invalid_base642553=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2554=== CONT TestParseSigningKey/no_colon2555=== RUN TestExternalSignerErrors/wrong_shape2556=== PAUSE TestExternalSignerErrors/wrong_shape2557=== RUN TestExternalSignerErrors/wrong_id2558=== PAUSE TestExternalSignerErrors/wrong_id2559=== RUN TestExternalSignerErrors/missing_signatures2560=== PAUSE TestExternalSignerErrors/missing_signatures2561=== RUN TestExternalSignerErrors/unrequested_key2562=== PAUSE TestExternalSignerErrors/unrequested_key2563=== RUN TestExternalSignerErrors/invalid_signature_base642564=== PAUSE TestExternalSignerErrors/invalid_signature_base642565=== RUN TestExternalSignerErrors/exit_at_startup2566=== PAUSE TestExternalSignerErrors/exit_at_startup2567=== RUN TestExternalSignerErrors/exit_on_request2568=== PAUSE TestGenerateFingerprint/no_references2569=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2570=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2571=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2572=== PAUSE TestExternalSignerErrors/exit_on_request2573=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2574=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2575--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2576 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2577 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2578 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2579 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2580 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2581=== RUN TestExternalSignerErrors/null_signatures2582=== PAUSE TestExternalSignerErrors/null_signatures2583=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2584=== RUN TestExternalSignerErrors/too_few_signatures2585=== PAUSE TestExternalSignerErrors/too_few_signatures2586=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2587=== RUN TestExternalSignerErrors/missing_signature_name2588=== RUN TestGenerateFingerprint/invalid_nar_hash_length2589=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2590=== RUN TestGenerateFingerprint/invalid_store_path_prefix2591=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2592=== PAUSE TestExternalSignerErrors/missing_signature_name2593=== RUN TestExternalSignerErrors/program_error2594=== PAUSE TestExternalSignerErrors/program_error2595=== RUN TestGenerateFingerprint/invalid_reference_prefix2596=== RUN TestExternalSignerErrors/invalid_JSON2597=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2598=== CONT TestGenerateFingerprint/basic_with_references2599=== CONT TestGenerateFingerprint/invalid_nar_hash_length2600=== CONT TestGenerateFingerprint/invalid_reference_prefix2601=== CONT TestGenerateFingerprint/no_references2602=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2603=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2604=== CONT TestGenerateFingerprint/invalid_store_path_prefix2605=== PAUSE TestExternalSignerErrors/invalid_JSON2606--- PASS: TestGenerateFingerprint (0.00s)2607 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2608 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2609 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2610 --- PASS: TestGenerateFingerprint/no_references (0.00s)2611 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2612 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2613 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2614=== RUN TestExternalSignerErrors/wrong_signature_name2615=== PAUSE TestExternalSignerErrors/wrong_signature_name2616=== RUN TestExternalSignerErrors/wrong_signature_length2617=== PAUSE TestExternalSignerErrors/wrong_signature_length2618=== RUN TestExternalSignerErrors/null2619=== PAUSE TestExternalSignerErrors/null2620=== RUN TestExternalSignerErrors/wrong_signatures_shape2621--- PASS: TestSign (0.00s)2622=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2623=== CONT TestExternalSignerErrors/wrong_shape2624=== CONT TestExternalSignerErrors/too_few_signatures2625=== RUN TestSignErrors/nil_key2626=== PAUSE TestSignErrors/nil_key2627=== RUN TestSignErrors/nil_narinfo2628=== CONT TestExternalSignerErrors/wrong_signature_name2629--- PASS: TestParseSigningKey (0.00s)2630 --- PASS: TestParseSigningKey/empty_name (0.00s)2631 --- PASS: TestParseSigningKey/wrong_length (0.00s)2632 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2633 --- PASS: TestParseSigningKey/no_colon (0.00s)2634 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2635 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2636=== CONT TestExternalSignerErrors/null_signatures2637=== CONT TestExternalSignerErrors/wrong_signatures_shape2638--- PASS: TestSignBatch (0.01s)2639=== CONT TestExternalSignerErrors/wrong_signature_length2640=== CONT TestExternalSignerErrors/missing_signatures2641=== CONT TestExternalSignerErrors/wrong_id2642=== CONT TestExternalSignerErrors/unrequested_key2643=== CONT TestExternalSignerErrors/invalid_JSON2644=== CONT TestExternalSignerErrors/program_error2645=== CONT TestExternalSignerErrors/missing_signature_name2646=== CONT TestExternalSignerErrors/invalid_signature_base642647=== PAUSE TestSignErrors/nil_narinfo2648=== CONT TestExternalSignerErrors/null2649=== CONT TestExternalSignerErrors/exit_at_startup2650=== RUN TestSignErrors/invalid_narinfo2651=== PAUSE TestSignErrors/invalid_narinfo2652=== RUN TestSignErrors/canceled2653=== PAUSE TestSignErrors/canceled2654=== CONT TestSignErrors/nil_key2655=== CONT TestSignErrors/canceled2656=== CONT TestSignErrors/nil_narinfo2657=== CONT TestExternalSignerErrors/exit_on_request2658=== CONT TestSignErrors/invalid_narinfo2659--- PASS: TestSignErrors (0.01s)2660 --- PASS: TestSignErrors/nil_key (0.00s)2661 --- PASS: TestSignErrors/canceled (0.00s)2662 --- PASS: TestSignErrors/nil_narinfo (0.00s)2663 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2664--- PASS: TestExternalSignerCancellation (0.11s)2665--- PASS: TestExternalSigner (0.18s)2666--- PASS: TestExternalSignerWrongPublicKey (0.23s)2667--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.30s)2668--- PASS: TestExternalSignerClose (0.37s)2669--- PASS: TestExternalSignerRestartsAfterCrash (0.88s)2670/private/var/tb/8/scratch/f058402f878f26dd/build/TestExternalSignerRestartsAfterCrash3493695141/001/sign program: line 7: /private/var/tb/8/scratch/f058402f878f26dd/build/TestExternalSignerRestartsAfterCrash3493695141/001/sign program.starts: No such file or directory2671--- PASS: TestExternalSignerErrors (0.00s)2672 --- PASS: TestExternalSignerErrors/exit_on_request (0.44s)2673 --- PASS: TestExternalSignerErrors/missing_signatures (0.51s)2674 --- PASS: TestExternalSignerErrors/wrong_shape (0.58s)2675 --- PASS: TestExternalSignerErrors/wrong_id (0.65s)2676 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.72s)2677 --- PASS: TestExternalSignerErrors/too_few_signatures (0.79s)2678 --- PASS: TestExternalSignerErrors/null (0.93s)2679 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.00s)2680 --- PASS: TestExternalSignerErrors/program_error (1.07s)2681 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.14s)2682 --- PASS: TestExternalSignerErrors/invalid_JSON (1.21s)2683 --- PASS: TestExternalSignerErrors/exit_at_startup (1.28s)2684 --- PASS: TestExternalSignerErrors/null_signatures (1.35s)2685 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.42s)2686 --- PASS: TestExternalSignerErrors/missing_signature_name (1.49s)2687 --- PASS: TestExternalSignerErrors/unrequested_key (1.57s)2688PASS2689Running OpenBao signer tests...2690=== RUN TestSign2691=== PAUSE TestSign2692=== RUN TestSignErrors2693=== PAUSE TestSignErrors2694=== RUN TestServe2695=== PAUSE TestServe2696=== RUN TestServeRejectsGarbage2697=== PAUSE TestServeRejectsGarbage2698=== CONT TestSign2699=== CONT TestServe2700=== CONT TestServeRejectsGarbage2701--- PASS: TestServeRejectsGarbage (0.00s)2702=== CONT TestSignErrors2703=== RUN TestSignErrors/http_error2704=== PAUSE TestSignErrors/http_error2705=== RUN TestSignErrors/invalid_json2706=== PAUSE TestSignErrors/invalid_json2707=== RUN TestSignErrors/no_prefix2708=== PAUSE TestSignErrors/no_prefix2709=== RUN TestSignErrors/invalid_base642710=== PAUSE TestSignErrors/invalid_base642711=== CONT TestSignErrors/http_error2712=== CONT TestSignErrors/no_prefix2713=== CONT TestSignErrors/invalid_base642714=== CONT TestSignErrors/invalid_json2715--- PASS: TestServe (0.00s)2716--- PASS: TestSign (0.00s)2717--- PASS: TestSignErrors (0.00s)2718 --- PASS: TestSignErrors/invalid_json (0.00s)2719 --- PASS: TestSignErrors/no_prefix (0.00s)2720 --- PASS: TestSignErrors/http_error (0.00s)2721 --- PASS: TestSignErrors/invalid_base64 (0.00s)2722PASS