niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #391
· 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.18s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestSetClientTLSErrors101=== CONT TestScriptTokenCachesUntilRefresh102=== CONT TestDoWithRetry_BodyReplayedViaGetBody103=== CONT TestSetClientTLSDoesNotMutateDefaultTransport104=== CONT TestSetClientTLS105=== CONT TestClientSignaturesByStorePath106--- PASS: TestClientSignaturesByStorePath (0.00s)107=== CONT TestStreamPushReportsSignatures108=== CONT TestParsePathInfoJSON109=== CONT TestStreamPushRequestLine110=== CONT TestStreamPushGivesUpOnDeadServer111=== CONT TestStreamPushIsolatesFailures112=== CONT TestStreamPushBatchesUnderLoad113=== CONT TestStreamPushReportsEveryPath114=== CONT TestShellSplitErrors115=== CONT TestShellSplit116=== CONT TestFileTokenMissing117=== CONT TestScriptTokenNoExpiryRerunsEveryCall118=== CONT TestFileTokenEmpty119=== CONT TestEncodeNixBase32120=== CONT TestResolveStorePath121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestRateLimiterFeedback123=== CONT TestPathInfoCACompatibility124=== CONT TestParsePathInfoJSONMultiplePaths125=== RUN TestParsePathInfoJSON/Nix_format1262026/10/07 06:12:45 WARN Rate limiter enabled after throttle name=server-test rate=51272026/10/07 06:12:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:523051282026/10/07 06:12:45 ERROR Upload failed error=boom count=11292026/10/07 06:12:45 ERROR Upload failed error="connection refused" count=201302026/10/07 06:12:45 ERROR Server seems unavailable, giving up on batch untried=171312026/10/07 06:12:45 ERROR Upload failed error=boom count=11322026/10/07 06:12:45 ERROR Upload failed error="bad path" count=3133--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)134=== CONT TestGetStorePathHash135=== RUN TestGetStorePathHash/valid_store_path136=== PAUSE TestGetStorePathHash/valid_store_path137=== RUN TestGetStorePathHash/basename_without_hyphen_should_error138=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error139=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error140=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error141=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error142=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error143=== CONT TestConvertHashToNix32144=== RUN TestConvertHashToNix32/SRI_format_to_Nix32145--- PASS: TestStreamPushIsolatesFailures (0.00s)146--- PASS: TestShellSplitErrors (0.00s)147--- PASS: TestStreamPushReportsEveryPath (0.00s)148--- PASS: TestShellSplit (0.00s)149=== CONT TestFileTokenReadsAndCaches150=== RUN TestEncodeNixBase32/test_string_hash151=== PAUSE TestEncodeNixBase32/test_string_hash152=== RUN TestEncodeNixBase32/empty_input153=== PAUSE TestEncodeNixBase32/empty_input154=== CONT TestPathInfoHashCompatibility155=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon159=== CONT TestEncodeNixBase32WithRealHash160=== RUN TestRateLimiterFeedback/429_enables_limiter161=== CONT TestUploadMultipart_PartsInParallel162=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166=== CONT TestDumpPathWriterError167=== CONT TestScriptTokenEmptyToken1682026/10/07 06:12:45 WARN Rate limiter enabled after throttle name=server-test rate=5169=== CONT TestStaticToken170=== CONT TestDumpPathSingleFile1712026/10/07 06:12:45 WARN Rate limiter backed off name=server-test rate=51722026/10/07 06:12:45 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52305173=== CONT TestScriptTokenBadJSON174=== CONT TestUploadMultipart_SupersededByPeer175=== RUN TestUploadMultipart_SupersededByPeer/exists176=== PAUSE TestRateLimiterFeedback/429_enables_limiter177=== RUN TestSetClientTLSErrors/missing_cert_file178--- PASS: TestStreamPushReportsSignatures (0.00s)179=== CONT TestScriptTokenScriptFails180=== CONT TestScriptTokenEmptyCommand181=== PAUSE TestParsePathInfoJSON/Nix_format182=== RUN TestPathInfoCACompatibility/null_ca_field183=== PAUSE TestSetClientTLSErrors/missing_cert_file184=== PAUSE TestPathInfoCACompatibility/null_ca_field185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text187=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive189=== RUN TestPathInfoCACompatibility/new_structured_format_-_text190=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text191=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== RUN TestSetClientTLSErrors/missing_key_file193=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI194=== CONT TestFilterOversizedClosures195=== CONT TestDumpPathMatchesNix196=== PAUSE TestSetClientTLSErrors/missing_key_file197=== RUN TestSetClientTLS/rejects_connection_without_client_cert198=== RUN TestSetClientTLSErrors/missing_ca_file199=== PAUSE TestSetClientTLSErrors/missing_ca_file200=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert201=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA202=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA203=== RUN TestSetClientTLS/preserves_debug_logging_transport204=== RUN TestSetClientTLSErrors/invalid_ca_file205=== PAUSE TestSetClientTLSErrors/invalid_ca_file206=== RUN TestRateLimiterFeedback/503_enables_limiter207=== PAUSE TestRateLimiterFeedback/503_enables_limiter208=== CONT TestCaseHackSuffix209=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter210=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter211=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter212=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter213=== CONT TestPartSizeForNAR214--- PASS: TestFileTokenMissing (0.00s)215--- PASS: TestFileTokenEmpty (0.00s)216=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32217=== RUN TestConvertHashToNix32/already_Nix32_format218=== PAUSE TestConvertHashToNix32/already_Nix32_format219=== RUN TestConvertHashToNix32/invalid_format220=== PAUSE TestConvertHashToNix32/invalid_format221=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun222=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method223=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method224=== RUN TestParsePathInfoJSON/Lix_format225=== PAUSE TestParsePathInfoJSON/Lix_format226=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512227=== RUN TestParsePathInfoJSON/empty_input228=== PAUSE TestParsePathInfoJSON/empty_input229=== CONT TestGetStorePathHash/valid_store_path230=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error231=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error232=== CONT TestGetStorePathHash/basename_without_hyphen_should_error233=== CONT TestEncodeNixBase32/test_string_hash234=== CONT TestEncodeNixBase32/empty_input235=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths236=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths237=== CONT TestSetClientTLSErrors/missing_cert_file238=== CONT TestSetClientTLSErrors/missing_ca_file239=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== CONT TestSetClientTLSErrors/missing_key_file241=== CONT TestRateLimiterFeedback/429_enables_limiter242=== RUN TestFilterOversizedClosures/no_limit_keeps_everything243=== CONT TestSetClientTLSErrors/invalid_ca_file244=== PAUSE TestUploadMultipart_SupersededByPeer/exists245=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything246=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica247=== RUN TestPartSizeForNAR/zero_stays_at_minimum248=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum249=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped251=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter252--- PASS: TestEncodeNixBase32WithRealHash (0.00s)253=== RUN TestFilterOversizedClosures/all_closures_skipped254=== CONT TestRegisterUploadedObjectReusesConnections255=== PAUSE TestFilterOversizedClosures/all_closures_skipped256=== PAUSE TestSetClientTLS/preserves_debug_logging_transport257--- PASS: TestStaticToken (0.00s)258--- PASS: TestDoServerRequestAttachesToken (0.01s)259=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter260--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)261=== RUN TestParsePathInfoJSON/whitespace_only262=== RUN TestUploadMultipart_SupersededByPeer/missing263=== PAUSE TestUploadMultipart_SupersededByPeer/missing264--- PASS: TestFileTokenReadsAndCaches (0.01s)265--- PASS: TestScriptTokenEmptyCommand (0.00s)266--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)267=== PAUSE TestParsePathInfoJSON/whitespace_only268=== RUN TestParsePathInfoJSON/invalid_JSON269=== PAUSE TestParsePathInfoJSON/invalid_JSON270=== RUN TestPartSizeForNAR/small_stays_at_minimum271=== PAUSE TestPartSizeForNAR/small_stays_at_minimum272=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum273=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum274=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts275=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts276=== RUN TestPartSizeForNAR/1_TiB277=== PAUSE TestPartSizeForNAR/1_TiB278=== RUN TestPartSizeForNAR/5_TiB_S3_max_object279=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object280=== RUN TestPartSizeForNAR/capped_at_5_GiB281=== PAUSE TestPartSizeForNAR/capped_at_5_GiB282=== CONT TestConvertHashToNix32/SRI_format_to_Nix32283--- PASS: TestResolveStorePath (0.01s)284=== CONT TestPathInfoCACompatibility/new_structured_format_-_text285=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI291=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon292--- PASS: TestPathInfoHashCompatibility (0.01s)293 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)294 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)295 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)296 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)297=== CONT TestFilterOversizedClosures/no_limit_keeps_everything2982026/10/07 06:12:45 INFO Garbage collection started299=== CONT TestFilterOversizedClosures/all_closures_skipped3002026/10/07 06:12:45 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50301=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3022026/10/07 06:12:45 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=2000303=== CONT TestSetClientTLS/rejects_connection_without_client_cert3042026/10/07 06:12:45 WARN Rate limiter enabled after throttle name=server-test rate=53052026/10/07 06:12:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:52314306=== CONT TestRateLimiterFeedback/503_enables_limiter307--- PASS: TestGetStorePathHash (0.00s)308 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)309 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3122026/10/07 06:12:45 WARN Rate limiter backed off name=server-test rate=5313=== CONT TestConvertHashToNix32/invalid_format314=== CONT TestSetClientTLS/preserves_debug_logging_transport315=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA316--- PASS: TestEncodeNixBase32 (0.00s)317 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)318 --- PASS: TestEncodeNixBase32/empty_input (0.00s)319--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)320 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)321 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)322--- PASS: TestFilterOversizedClosures (0.00s)323 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)324 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)326=== CONT TestConvertHashToNix32/already_Nix32_format327=== CONT TestPathInfoCACompatibility/null_ca_field328--- PASS: TestConvertHashToNix32 (0.01s)329 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)330 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)331 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)332=== CONT TestUploadMultipart_SupersededByPeer/exists333--- PASS: TestPathInfoCACompatibility (0.01s)334 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)338 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)339=== CONT TestParsePathInfoJSON/Nix_format340=== CONT TestPartSizeForNAR/zero_stays_at_minimum341=== CONT TestUploadMultipart_SupersededByPeer/missing342--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)343=== CONT TestParsePathInfoJSON/invalid_JSON344=== CONT TestParsePathInfoJSON/whitespace_only345=== CONT TestParsePathInfoJSON/empty_input346=== CONT TestParsePathInfoJSON/Lix_format347--- PASS: TestScriptTokenScriptFails (0.01s)348=== CONT TestPartSizeForNAR/1_TiB349--- PASS: TestParsePathInfoJSON (0.01s)350 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)353 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)354 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum357=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts358=== CONT TestPartSizeForNAR/5_TiB_S3_max_object359=== CONT TestPartSizeForNAR/small_stays_at_minimum360--- PASS: TestPartSizeForNAR (0.00s)361 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)366 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)367 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)368--- PASS: TestSetClientTLSErrors (0.01s)369 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)370 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)372 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)373--- PASS: TestScriptTokenEmptyToken (0.02s)3742026/10/07 06:12:45 WARN Rate limiter enabled after throttle name=server-test rate=53752026/10/07 06:12:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:523243762026/10/07 06:12:45 INFO Garbage collection started3772026/10/07 06:12:45 WARN Rate limiter backed off name=server-test rate=5378--- PASS: TestStreamPushRequestLine (0.03s)3792026/10/07 06:12:45 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0380--- PASS: TestRateLimiterFeedback (0.01s)381 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)382 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)383 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)384 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)385--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)386 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)387 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)3882026/10/07 06:12:45 WARN Garbage collection finished on another replica. Its statistics are not available here389--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)390--- PASS: TestScriptTokenBadJSON (0.03s)3912026/10/07 06:12:45 http: TLS handshake error from 127.0.0.1:52333: read tcp 127.0.0.1:52308->127.0.0.1:52333: use of closed network connection392--- PASS: TestSetClientTLS (0.01s)393 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)395 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.04s)396--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)397--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)399--- PASS: TestDumpPathWriterError (0.08s)400--- PASS: TestStreamPushBatchesUnderLoad (0.11s)401--- PASS: TestDumpPathSingleFile (0.11s)402--- PASS: TestCaseHackSuffix (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.63s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "_tribuchetbld6".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/postgres1428319299/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/postgres1428319299/data -l logfile start4344352026-10-07 06:12:48.565 UTC [75475] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-07 06:12:48.565 UTC [75475] LOG: listening on Unix socket "/private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/postgres1428319299/.s.PGSQL.5432"4372026-10-07 06:12:48.568 UTC [75497] LOG: database system was shut down at 2026-10-07 06:12:48 UTC4382026-10-07 06:12:48.569 UTC [75475] LOG: database system is ready to accept connections439/private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/postgres1428319299:5432 - accepting connections440{"timestamp":"2026-10-07T06:12:50.730611Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ca2bf295-85a0-4a2d-bf72-538405d5715c","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(8)"}441{"timestamp":"2026-10-07T06:12:50.834012Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"753a92db-aba7-4a76-9778-0c5c565191ae","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)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/07 06:12:51 INFO lead: acquired remote=192.0.2.1:12344902026/10/07 06:12:51 INFO lead: released remote=192.0.2.1:12344912026/10/07 06:12:52 INFO lead: acquired remote=192.0.2.1:12344922026/10/07 06:12:53 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (2.20s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/07 06:12:53 INFO lead: acquired remote=192.0.2.1:12345002026-10-07 06:12:54.749 UTC [76266] FATAL: terminating connection due to administrator command5012026/10/07 06:12:54 INFO lead: acquired remote=192.0.2.1:12345022026/10/07 06:12:55 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/07 06:12:55 INFO lead: released remote=192.0.2.1:12345042026/10/07 06:12:56 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (3.01s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestMetricsCommit575=== PAUSE TestMetricsCommit576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestObjectStatsLargeCommit589=== PAUSE TestObjectStatsLargeCommit590=== RUN TestOrphanedObjectsGC591=== PAUSE TestOrphanedObjectsGC592=== RUN TestOrphanedObjectsGCStressTest593=== PAUSE TestOrphanedObjectsGCStressTest594=== RUN TestCreatePin_ReservedPins595=== PAUSE TestCreatePin_ReservedPins596=== RUN TestPresentReportsOnlyClosureRoots597=== PAUSE TestPresentReportsOnlyClosureRoots598=== RUN TestPresentRefreshesOnlyStaleClosures599=== PAUSE TestPresentRefreshesOnlyStaleClosures600=== RUN TestPresentNotReportedWhileGCDeletesClosure601=== PAUSE TestPresentNotReportedWhileGCDeletesClosure602=== RUN TestParseSingleRange603=== PAUSE TestParseSingleRange604=== RUN TestProxyHeadersOnlyTrustedOnSocket605=== PAUSE TestProxyHeadersOnlyTrustedOnSocket606=== RUN TestIsValidCachePath607=== PAUSE TestIsValidCachePath608=== RUN TestReadProxyNarinfo609=== PAUSE TestReadProxyNarinfo610=== RUN TestReadProxyNarinfoAlreadyDecompressed611=== PAUSE TestReadProxyNarinfoAlreadyDecompressed612=== RUN TestReadProxyContentNegotiation613=== PAUSE TestReadProxyContentNegotiation614=== RUN TestReadProxyNarStreaming615=== PAUSE TestReadProxyNarStreaming616=== RUN TestReadProxy404617=== PAUSE TestReadProxy404618=== RUN TestReadProxyInvalidPath619=== PAUSE TestReadProxyInvalidPath620=== RUN TestReadProxyHead621=== PAUSE TestReadProxyHead622=== RUN TestReadProxyOutlastsServerWriteTimeout623=== PAUSE TestReadProxyOutlastsServerWriteTimeout624=== RUN TestReadProxyConditionalGet625=== PAUSE TestReadProxyConditionalGet626=== RUN TestReadProxyRootRedirectsToIndexHTML627=== PAUSE TestReadProxyRootRedirectsToIndexHTML628=== RUN TestReadProxyDisabled629=== PAUSE TestReadProxyDisabled630=== RUN TestReadRedirectNar631=== PAUSE TestReadRedirectNar632=== RUN TestReadRedirectKeepsNarinfoProxied633=== PAUSE TestReadRedirectKeepsNarinfoProxied634=== RUN TestReadProxyRangeRequest635=== PAUSE TestReadProxyRangeRequest636=== RUN TestReadRedirectUsesPublicS3URL637=== PAUSE TestReadRedirectUsesPublicS3URL638=== RUN TestPush_OverlappingRootsStoreOneRowPerKey639=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey640=== RUN TestPush_CompleteCommitsEveryRoot641=== PAUSE TestPush_CompleteCommitsEveryRoot642=== RUN TestPush_RepeatedRootCommitsOnce643=== PAUSE TestPush_RepeatedRootCommitsOnce644=== RUN TestPush_CompleteWaitsForCleanupOfThePush645=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush646=== RUN TestPush_RootsAreLockedInByteOrder647=== PAUSE TestPush_RootsAreLockedInByteOrder648=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit649=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit650=== RUN TestPush_RejectsBadRequests651=== PAUSE TestPush_RejectsBadRequests652=== RUN TestPush_SignsNarinfosOfItsPendingObjects653=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects654=== RUN TestRedundantMultipartUpload655=== PAUSE TestRedundantMultipartUpload656=== RUN TestCompleteMultipartUpload_ErrorButObjectExists657=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists658=== RUN TestCompletedNarNotReofferedAcrossClosures659=== PAUSE TestCompletedNarNotReofferedAcrossClosures660=== RUN TestPresignedUploadRegisteredBeforeCommit661=== PAUSE TestPresignedUploadRegisteredBeforeCommit662=== RUN TestService_Rustfstest663=== PAUSE TestService_Rustfstest664=== RUN TestParseSize665=== PAUSE TestParseSize666=== RUN TestSkippedUploadsHandler667=== PAUSE TestSkippedUploadsHandler668=== RUN TestSystemdListenerNotActivated669--- PASS: TestSystemdListenerNotActivated (0.00s)670=== RUN TestWatchdogBeatsWhenHealthy671 systemd_test.go:74: unexpected error: listen unixgram /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestWatchdogBeatsWhenHealthy759071546/001/notify.sock: bind: invalid argument672 673--- FAIL: TestWatchdogBeatsWhenHealthy (0.00s)674=== RUN TestWatchdogSkipsWhenUnhealthy675 systemd_test.go:94: unexpected error: listen unixgram /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestWatchdogSkipsWhenUnhealthy335903513/001/notify.sock: bind: invalid argument676 677--- FAIL: TestWatchdogSkipsWhenUnhealthy (0.00s)678=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle679=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle680=== RUN TestProxyWriteTimeout681=== PAUSE TestProxyWriteTimeout682=== RUN TestPendingClosureWriteTimeout683=== PAUSE TestPendingClosureWriteTimeout684=== RUN TestIsValidUploadKey685=== PAUSE TestIsValidUploadKey686=== RUN TestUploadHandlersRejectInvalidKeys687=== PAUSE TestUploadHandlersRejectInvalidKeys688=== RUN TestUploadHandlersRejectOversizedBody689=== PAUSE TestUploadHandlersRejectOversizedBody690=== RUN TestService_cleanupPendingClosuresHandler691=== PAUSE TestService_cleanupPendingClosuresHandler692=== RUN TestService_createPendingClosureHandler693=== PAUSE TestService_createPendingClosureHandler694=== RUN TestService_verifyS3Integrity695=== PAUSE TestService_verifyS3Integrity696=== RUN TestCompleteMultipartUnregistered697=== PAUSE TestCompleteMultipartUnregistered698=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT699=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT700=== CONT TestPush_CompleteCommitsEveryRoot701=== CONT TestPushWaitsForSweepHoldingRow702=== CONT TestReadProxyOutlastsServerWriteTimeout703=== CONT TestSkippedUploadsHandler704=== CONT TestPush_OverlappingRootsStoreOneRowPerKey705=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT706=== CONT TestReadRedirectUsesPublicS3URL707=== CONT TestCompleteMultipartUnregistered708=== CONT TestService_verifyS3Integrity709=== CONT TestReadProxyRangeRequest710=== CONT TestService_createPendingClosureHandler711=== CONT TestService_cleanupPendingClosuresHandler712=== CONT TestReadRedirectKeepsNarinfoProxied713=== CONT TestUploadHandlersRejectOversizedBody714=== CONT TestReadRedirectNar7152026/10/07 06:12:56 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000716=== CONT TestProxyWriteTimeout717=== CONT TestReadProxyDisabled718=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== RUN TestProxyWriteTimeout/narinfo720=== CONT TestReadProxyRootRedirectsToIndexHTML721=== CONT TestReadProxyConditionalGet722=== CONT TestCommitRacingPendingCleanupKeepsObjects723=== CONT TestGCEndsOnShutdown724=== CONT TestReadProxyHead725=== CONT TestService_AuthMiddleware726--- PASS: TestSkippedUploadsHandler (0.01s)727=== PAUSE TestProxyWriteTimeout/narinfo728=== RUN TestProxyWriteTimeout/1_GiB_nar729=== PAUSE TestProxyWriteTimeout/1_GiB_nar730=== RUN TestProxyWriteTimeout/10_GiB_nar731=== PAUSE TestProxyWriteTimeout/10_GiB_nar732=== RUN TestProxyWriteTimeout/unknown_size733=== PAUSE TestProxyWriteTimeout/unknown_size734=== CONT TestReadProxy404735=== RUN TestGCEndsOnShutdown/before_the_run736=== PAUSE TestGCEndsOnShutdown/before_the_run737=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete738=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete739=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark740=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark741=== CONT TestReadProxyNarStreaming742=== CONT TestReadProxyInvalidPath743=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure744=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure745=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart746=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart747=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts748=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts749=== CONT TestReadProxyContentNegotiation7502026/10/07 06:12:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7512026/10/07 06:12:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst752--- PASS: TestCompleteMultipartUnregistered (1.03s)753=== CONT TestReadProxyNarinfoAlreadyDecompressed7542026/10/07 06:12:57 INFO Received uploads request method=POST path=/api/pending_closures7552026/10/07 06:12:57 INFO Received push request method=POST path=/api/pushes756--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.80s)757=== CONT TestReadProxyNarinfo758--- PASS: TestPushWaitsForSweepHoldingRow (1.93s)759=== CONT TestIsValidCachePath760=== RUN TestIsValidCachePath/narinfo761=== PAUSE TestIsValidCachePath/narinfo762=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars763=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars764=== RUN TestIsValidCachePath/nar_zst765=== PAUSE TestIsValidCachePath/nar_zst766=== RUN TestIsValidCachePath/nar_xz767=== PAUSE TestIsValidCachePath/nar_xz768=== RUN TestIsValidCachePath/nar_bz2769=== PAUSE TestIsValidCachePath/nar_bz2770=== RUN TestIsValidCachePath/nar_uncompressed771=== PAUSE TestIsValidCachePath/nar_uncompressed772=== RUN TestIsValidCachePath/ls773=== PAUSE TestIsValidCachePath/ls774=== RUN TestIsValidCachePath/log775=== PAUSE TestIsValidCachePath/log776=== RUN TestIsValidCachePath/realisation777=== PAUSE TestIsValidCachePath/realisation778=== RUN TestIsValidCachePath/nix-cache-info779=== PAUSE TestIsValidCachePath/nix-cache-info780=== RUN TestIsValidCachePath/index.html781=== PAUSE TestIsValidCachePath/index.html782=== RUN TestIsValidCachePath/traversal_parent783=== PAUSE TestIsValidCachePath/traversal_parent784=== RUN TestIsValidCachePath/traversal_in_middle785=== PAUSE TestIsValidCachePath/traversal_in_middle786=== RUN TestIsValidCachePath/invalid_char_e787=== PAUSE TestIsValidCachePath/invalid_char_e788=== RUN TestIsValidCachePath/invalid_char_u789=== PAUSE TestIsValidCachePath/invalid_char_u790=== RUN TestIsValidCachePath/random_path791=== PAUSE TestIsValidCachePath/random_path792=== RUN TestIsValidCachePath/empty793=== PAUSE TestIsValidCachePath/empty794=== RUN TestIsValidCachePath/leading_slash795=== PAUSE TestIsValidCachePath/leading_slash796=== RUN TestIsValidCachePath/wrong_extension797=== PAUSE TestIsValidCachePath/wrong_extension798=== RUN TestIsValidCachePath/short_hash799=== PAUSE TestIsValidCachePath/short_hash800=== CONT TestProxyHeadersOnlyTrustedOnSocket801--- PASS: TestReadRedirectUsesPublicS3URL (2.02s)802=== CONT TestPendingClosureWriteTimeout803=== RUN TestPendingClosureWriteTimeout/empty804=== PAUSE TestPendingClosureWriteTimeout/empty805=== RUN TestPendingClosureWriteTimeout/400_objects806=== PAUSE TestPendingClosureWriteTimeout/400_objects807=== RUN TestPendingClosureWriteTimeout/670k_objects808=== PAUSE TestPendingClosureWriteTimeout/670k_objects809=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline810=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline811=== CONT TestUploadHandlersRejectInvalidKeys812=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info813=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info814=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal815=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal816=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key817=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key818=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key819=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key820=== CONT TestIsValidUploadKey821=== RUN TestIsValidUploadKey/narinfo822=== PAUSE TestIsValidUploadKey/narinfo823=== RUN TestIsValidUploadKey/nar_zst824=== PAUSE TestIsValidUploadKey/nar_zst825=== RUN TestIsValidUploadKey/nar_xz826=== PAUSE TestIsValidUploadKey/nar_xz827=== RUN TestIsValidUploadKey/nar_plain828=== PAUSE TestIsValidUploadKey/nar_plain829=== RUN TestIsValidUploadKey/listing830=== PAUSE TestIsValidUploadKey/listing831=== RUN TestIsValidUploadKey/build_log832=== PAUSE TestIsValidUploadKey/build_log833=== RUN TestIsValidUploadKey/build_log_home-manager_file834=== PAUSE TestIsValidUploadKey/build_log_home-manager_file835=== RUN TestIsValidUploadKey/build_log_plus_in_name836=== PAUSE TestIsValidUploadKey/build_log_plus_in_name837=== RUN TestIsValidUploadKey/build_log_question_mark838=== PAUSE TestIsValidUploadKey/build_log_question_mark839=== RUN TestIsValidUploadKey/build_log_equals840=== PAUSE TestIsValidUploadKey/build_log_equals841=== RUN TestIsValidUploadKey/realisation842=== PAUSE TestIsValidUploadKey/realisation843=== RUN TestIsValidUploadKey/realisation_plus_in_output844=== PAUSE TestIsValidUploadKey/realisation_plus_in_output845=== RUN TestIsValidUploadKey/nix-cache-info846=== PAUSE TestIsValidUploadKey/nix-cache-info847=== RUN TestIsValidUploadKey/index.html848=== PAUSE TestIsValidUploadKey/index.html849=== RUN TestIsValidUploadKey/narinfo_key,_nar_type850=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type851=== RUN TestIsValidUploadKey/nar_key,_narinfo_type852=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type853=== RUN TestIsValidUploadKey/listing_key,_narinfo_type854=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type855=== RUN TestIsValidUploadKey/traversal856=== PAUSE TestIsValidUploadKey/traversal857=== RUN TestIsValidUploadKey/traversal_nar858=== PAUSE TestIsValidUploadKey/traversal_nar859=== RUN TestIsValidUploadKey/absolute860=== PAUSE TestIsValidUploadKey/absolute861=== RUN TestIsValidUploadKey/empty_key862=== PAUSE TestIsValidUploadKey/empty_key863=== RUN TestIsValidUploadKey/unknown_type864=== PAUSE TestIsValidUploadKey/unknown_type865=== CONT TestRedundantMultipartUpload8662026/10/07 06:12:58 INFO Received push request method=POST path=/api/pushes8672026/10/07 06:12:58 INFO Received complete push request method=POST path=/api/pushes/1/complete8682026/10/07 06:12:58 INFO Completed push id=1 objects=6 duration=18.795625ms869--- PASS: TestPush_CompleteCommitsEveryRoot (2.41s)870=== CONT TestParseSize871--- PASS: TestParseSize (0.00s)872=== CONT TestService_Rustfstest873--- PASS: TestReadProxyRangeRequest (2.81s)874=== CONT TestPresignedUploadRegisteredBeforeCommit8752026/10/07 06:12:59 INFO Received uploads request method=POST path=/api/pending_closures876--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.08s)877=== CONT TestCompletedNarNotReofferedAcrossClosures878--- PASS: TestReadRedirectNar (3.23s)879=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8802026/10/07 06:12:59 INFO Aborted multipart uploads count=0 kept=08812026/10/07 06:12:59 WARN Force mode enabled - objects will be deleted immediately without grace period8822026/10/07 06:12:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08832026/10/07 06:12:59 INFO Vacuumed table table=pending_closures8842026/10/07 06:12:59 INFO Vacuumed table table=pending_objects8852026/10/07 06:12:59 INFO Vacuumed table table=multipart_uploads8862026/10/07 06:12:59 INFO Vacuumed table table=closures8872026/10/07 06:12:59 INFO Vacuumed table table=objects888--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.69s)889=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit8902026/10/07 06:12:59 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/07 06:12:59 INFO Received uploads request method=POST path=/api/pending_closures8922026/10/07 06:12:59 INFO Received uploads request method=POST path=/api/pending_closures893--- PASS: TestReadRedirectKeepsNarinfoProxied (4.10s)894=== CONT TestPush_SignsNarinfosOfItsPendingObjects8952026/10/07 06:13:00 INFO Received cleanup request method=DELETE path=/api/pending_closures8962026/10/07 06:13:00 INFO Aborted multipart uploads count=0 kept=08972026/10/07 06:13:00 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/07 06:13:00 INFO Received cleanup request method=DELETE path=/api/pending_closures8992026/10/07 06:13:00 INFO Aborted multipart uploads count=1 kept=09002026/10/07 06:13:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9012026-10-07 06:13:00.746 UTC [78092] ERROR: Closure does not exist: id=19022026-10-07 06:13:00.746 UTC [78092] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9032026-10-07 06:13:00.746 UTC [78092] STATEMENT: -- name: CommitPendingClosure :one904 SELECT commit_pending_closure($1::bigint)::bigint905 906--- PASS: TestService_cleanupPendingClosuresHandler (4.60s)907=== CONT TestPush_RejectsBadRequests908--- PASS: TestReadProxyDisabled (4.72s)909=== CONT TestPush_CompleteWaitsForCleanupOfThePush9102026/10/07 06:13:01 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/07 06:13:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete912--- PASS: TestReadProxyRootRedirectsToIndexHTML (5.37s)913=== CONT TestPush_RootsAreLockedInByteOrder9142026/10/07 06:13:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9152026/10/07 06:13:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLjNkZTU3NzAwLTYwOTQtNDZlYS05ZWJlLTJmY2FjZjUyOWQ3M3gxNzkxMzUzNTc5OTU2MzI0MDAw parts=109162026/10/07 06:13:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9172026/10/07 06:13:01 INFO Completed upload id=1 objects=2 duration=17.08025ms9182026/10/07 06:13:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009192026/10/07 06:13:01 INFO Received uploads request method=POST path=/api/pending_closures9202026/10/07 06:13:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures9212026/10/07 06:13:01 INFO Aborted multipart uploads count=0 kept=09222026/10/07 06:13:01 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=09232026/10/07 06:13:01 INFO Vacuumed table table=pending_closures9242026/10/07 06:13:01 INFO Vacuumed table table=pending_objects9252026/10/07 06:13:01 INFO Vacuumed table table=multipart_uploads9262026/10/07 06:13:01 INFO Vacuumed table table=closures927--- PASS: TestReadProxyInvalidPath (5.58s)928=== CONT TestResolveDBConnectionString9292026/10/07 06:13:01 INFO Vacuumed table table=objects930=== RUN TestResolveDBConnectionString/flag_wins931=== PAUSE TestResolveDBConnectionString/flag_wins932=== RUN TestResolveDBConnectionString/file_when_flag_empty933=== PAUSE TestResolveDBConnectionString/file_when_flag_empty934=== RUN TestResolveDBConnectionString/missing_file_is_an_error935=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error936=== RUN TestResolveDBConnectionString/PGHOST_allows_empty937=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty938=== RUN TestResolveDBConnectionString/nothing_configured939=== PAUSE TestResolveDBConnectionString/nothing_configured940=== CONT TestSweepRechecksPendingAfterLocking9412026/10/07 06:13:01 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000942--- PASS: TestService_createPendingClosureHandler (5.68s)943=== CONT TestGetExistingObjectsLocksRows944--- PASS: TestReadProxy404 (5.92s)945=== CONT TestRegisterCompletedObjectNeedsPendingRow9462026/10/07 06:13:02 INFO Received uploads request method=POST path=/api/pending_closures947--- PASS: TestReadProxyNarStreaming (6.40s)948=== CONT TestSweepSkipsRowsLockedByPush949--- PASS: TestReadProxyConditionalGet (6.75s)950=== CONT TestFailedS3DeleteKeepsTombstone951--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.81s)952=== CONT TestForceGCDuringPushOffersSweptObject953=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows954=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows955=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check956=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check957=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9582026/10/07 06:13:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"959--- PASS: TestService_AuthMiddleware (7.07s)960=== CONT TestGCSweepDeliversEachKeyOnce961--- PASS: TestReadProxyContentNegotiation (7.50s)962=== CONT TestTombstonedObjectOfferedWithoutWaiting963--- PASS: TestReadProxyHead (7.77s)964=== CONT TestGCSweepSkipsPendingObjects9652026/10/07 06:13:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9662026/10/07 06:13:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLjY1N2Q4MjExLTRmNWItNGQzYi05MjliLWIxYmVmZDUxODYzZXgxNzkxMzUzNTgyMzMxNTM2MDAw parts=109672026/10/07 06:13:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9682026/10/07 06:13:04 INFO Completed upload id=1 objects=2 duration=28.931333ms9692026/10/07 06:13:04 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/07 06:13:04 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/07 06:13:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9722026/10/07 06:13:04 WARN Found objects in DB but missing from S3, will re-upload count=1973--- PASS: TestService_verifyS3Integrity (8.08s)974=== CONT TestDeduplicatedObjectsRecordedAsPending975--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.19s)976=== CONT TestPushDedupSurvivesConcurrentGC9772026/10/07 06:13:04 WARN Rate limiter enabled after throttle name=s3-test rate=59782026/10/07 06:13:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."979=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle980 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=10981 throttle_test.go:215: Rate limiter: enabled=true, rate=5.00982--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.57s)983=== CONT TestGCMetrics984=== NAME TestProxyHeadersOnlyTrustedOnSocket985 proxy_socket_test.go:36: unexpected error: listen unix /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestProxyHeadersOnlyTrustedOnSocket1401114439/001/proxy.sock: bind: invalid argument986 987--- FAIL: TestProxyHeadersOnlyTrustedOnSocket (6.75s)988=== CONT TestGCBugBareHashReferences9892026/10/07 06:13:05 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>990--- PASS: TestReadProxyNarinfo (7.34s)991=== CONT TestGCAdvisoryLockBlocksConcurrentRun9922026/10/07 06:13:05 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/07 06:13:05 INFO Received uploads request method=POST path=/api/pending_closures994--- PASS: TestService_Rustfstest (7.33s)995=== CONT TestLeadEndsOnShutdown9962026/10/07 06:13:06 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/07 06:13:06 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9982026/10/07 06:13:06 INFO Received uploads request method=POST path=/api/pending_closures999--- PASS: TestPresignedUploadRegisteredBeforeCommit (7.52s)1000=== CONT TestLeadIncumbentAnnouncesAtOnce10012026/10/07 06:13:06 INFO Received uploads request method=POST path=/api/pending_closures10022026/10/07 06:13:07 INFO Received uploads request method=POST path=/api/pending_closures10032026/10/07 06:13:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/10/07 06:13:07 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLmFiOWQ1MjUzLTQ3MzYtNDk4MS1iNDM5LTIxOTI2NDg3NTEzZXgxNzkxMzUzNTg3MTE3NDQ5MDAw10052026/10/07 06:13:07 INFO Received push request method=POST path=/api/pushes10062026/10/07 06:13:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLmFiOWQ1MjUzLTQ3MzYtNDk4MS1iNDM5LTIxOTI2NDg3NTEzZXgxNzkxMzUzNTg3MTE3NDQ5MDAw parts=11007--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.17s)1008=== CONT TestLeadElectsOneAndHandsOver10092026/10/07 06:13:07 INFO Received complete push request method=POST path=/api/pushes/1/complete10102026/10/07 06:13:07 INFO Completed push id=1 objects=4 duration=44.871208ms10112026/10/07 06:13:07 INFO Received push request method=POST path=/api/pushes10122026/10/07 06:13:07 INFO Aborted multipart uploads count=0 kept=010132026/10/07 06:13:07 WARN Force mode enabled - objects will be deleted immediately without grace period10142026/10/07 06:13:07 INFO Received push request method=POST path=/api/pushes10152026/10/07 06:13:07 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=010162026/10/07 06:13:08 INFO Vacuumed table table=pending_closures10172026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10182026/10/07 06:13:08 INFO Vacuumed table table=pending_objects10192026/10/07 06:13:08 INFO Signed narinfos id=1 count=110202026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10212026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/07 06:13:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10232026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10242026/10/07 06:13:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10252026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10262026/10/07 06:13:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110272026/10/07 06:13:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10282026/10/07 06:13:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1029--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.89s)1030=== CONT TestConnectWaitsForAPeerMigration10312026/10/07 06:13:08 INFO Vacuumed table table=multipart_uploads10322026/10/07 06:13:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/10/07 06:13:08 INFO Vacuumed table table=closures10342026/10/07 06:13:08 INFO Vacuumed table table=objects10352026/10/07 06:13:08 INFO Received complete push request method=POST path=/api/pushes/2/complete10362026/10/07 06:13:08 INFO Completed push id=2 objects=4 duration=13.923708ms1037--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (8.43s)1038=== CONT TestParseSingleRange1039=== RUN TestParseSingleRange/none1040=== PAUSE TestParseSingleRange/none1041=== RUN TestParseSingleRange/unknown_unit1042=== PAUSE TestParseSingleRange/unknown_unit1043=== RUN TestParseSingleRange/multi-range_ignored1044=== PAUSE TestParseSingleRange/multi-range_ignored1045=== RUN TestParseSingleRange/malformed_no_dash1046=== PAUSE TestParseSingleRange/malformed_no_dash1047=== RUN TestParseSingleRange/malformed_both_empty1048=== PAUSE TestParseSingleRange/malformed_both_empty1049=== RUN TestParseSingleRange/malformed_end_before_start1050=== PAUSE TestParseSingleRange/malformed_end_before_start1051=== RUN TestParseSingleRange/closed1052=== PAUSE TestParseSingleRange/closed1053=== RUN TestParseSingleRange/open-ended1054=== PAUSE TestParseSingleRange/open-ended1055=== RUN TestParseSingleRange/end_clamped_to_size1056=== PAUSE TestParseSingleRange/end_clamped_to_size1057=== RUN TestParseSingleRange/suffix1058=== PAUSE TestParseSingleRange/suffix1059=== RUN TestParseSingleRange/suffix_exceeds_size1060=== PAUSE TestParseSingleRange/suffix_exceeds_size1061=== RUN TestParseSingleRange/single_byte1062=== PAUSE TestParseSingleRange/single_byte1063=== RUN TestParseSingleRange/start_past_EOF1064=== PAUSE TestParseSingleRange/start_past_EOF1065=== RUN TestParseSingleRange/start_far_past_EOF1066=== PAUSE TestParseSingleRange/start_far_past_EOF1067=== CONT TestNARDeduplicationMetadataUploadBug10682026/10/07 06:13:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLjg2MWJhNGRlLWNmMjctNGJiOC1hZWQwLWEyYjM3MjFlNzBhZngxNzkxMzUzNTg1NzA3NjIwMDAw parts=1210692026/10/07 06:13:08 INFO Received uploads request method=POST path=/api/pending_closures1070=== RUN TestPush_RejectsBadRequests/no_roots1071=== PAUSE TestPush_RejectsBadRequests/no_roots1072=== RUN TestPush_RejectsBadRequests/no_objects1073=== PAUSE TestPush_RejectsBadRequests/no_objects1074=== RUN TestPush_RejectsBadRequests/bad_root1075=== PAUSE TestPush_RejectsBadRequests/bad_root10762026/10/07 06:13:08 INFO Received uploads request method=POST path=/api/pending_closures1077=== RUN TestPush_RejectsBadRequests/root_not_in_objects1078=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1079=== CONT TestCreatePendingClosureRejectsOversizedNAR10802026/10/07 06:13:08 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1082=== CONT TestCacheConfigHandlerMaxNarSize1083--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1084=== CONT TestGenerateLandingPage1085--- PASS: TestGenerateLandingPage (0.00s)1086=== CONT TestService_readinessHandler10872026/10/07 06:13:08 INFO Received push request method=POST path=/api/pushes10882026/10/07 06:13:09 INFO Received push request method=POST path=/api/pushes10892026-10-07 06:13:09.281 UTC [78213] ERROR: Push does not exist: id=110902026-10-07 06:13:09.281 UTC [78213] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10912026-10-07 06:13:09.281 UTC [78213] STATEMENT: SELECT commit_push($1)1092--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (8.41s)1093=== CONT TestService_healthCheckHandler10942026/10/07 06:13:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10952026-10-07 06:13:09.558 UTC [78218] ERROR: could not obtain lock on row in relation "closures"10962026-10-07 06:13:09.558 UTC [78218] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10972026-10-07 06:13:09.564 UTC [78218] ERROR: could not obtain lock on row in relation "closures"10982026-10-07 06:13:09.564 UTC [78218] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10992026-10-07 06:13:09.566 UTC [78218] ERROR: could not obtain lock on row in relation "closures"11002026-10-07 06:13:09.566 UTC [78218] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11012026-10-07 06:13:09.567 UTC [78218] ERROR: could not obtain lock on row in relation "closures"11022026-10-07 06:13:09.567 UTC [78218] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11032026-10-07 06:13:09.574 UTC [78218] ERROR: could not obtain lock on row in relation "closures"11042026-10-07 06:13:09.574 UTC [78218] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1105--- PASS: TestPush_RootsAreLockedInByteOrder (8.05s)1106=== CONT TestMetricsInventory11072026/10/07 06:13:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLjIxYTM5NmRkLTVmZjYtNGFlNy05NjY5LTY1ZWNlNGFjMTA2NngxNzkxMzUzNTg2ODEzNzYyMDAw parts=1211082026/10/07 06:13:09 INFO Received uploads request method=POST path=/api/pending_closures1109--- PASS: TestCompletedNarNotReofferedAcrossClosures (10.39s)1110=== CONT TestGracefulShutdownDrainsInflight11112026/10/07 06:13:09 INFO Starting HTTP server address=127.0.0.1:5261611122026/10/07 06:13:09 INFO Shutdown signal received, draining in-flight requests timeout=10s1113--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1114=== CONT TestPresentNotReportedWhileGCDeletesClosure1115=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1116=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1117=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1118=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1119=== CONT TestGCTaskStore_Fail1120--- PASS: TestGCTaskStore_Fail (0.00s)1121=== CONT TestPresentRefreshesOnlyStaleClosures11222026/10/07 06:13:09 INFO Aborted multipart uploads count=0 kept=011232026/10/07 06:13:09 WARN Force mode enabled - objects will be deleted immediately without grace period11242026/10/07 06:13:09 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=011252026/10/07 06:13:10 INFO Vacuumed table table=pending_closures11262026/10/07 06:13:10 INFO Vacuumed table table=pending_objects11272026/10/07 06:13:10 INFO Vacuumed table table=multipart_uploads11282026/10/07 06:13:10 INFO Vacuumed table table=closures11292026/10/07 06:13:10 INFO Vacuumed table table=objects1130--- PASS: TestSweepRechecksPendingAfterLocking (8.27s)1131=== CONT TestGCTaskStore_PhaseUpdates1132--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1133=== CONT TestPresentReportsOnlyClosureRoots1134--- PASS: TestGetExistingObjectsLocksRows (8.45s)1135=== CONT TestGCTaskStore_CompletedAllowsNewTask1136--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1137=== CONT TestCreatePin_ReservedPins11382026/10/07 06:13:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52622/oidc1139--- PASS: TestRegisterCompletedObjectNeedsPendingRow (8.43s)1140=== CONT TestOrphanedObjectsGCStressTest11412026/10/07 06:13:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/10/07 06:13:10 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLmU0Zjc5ODAyLTlmYWYtNDAwNi05YmM2LTAyOTk5ZjE3YmY3YXgxNzkxMzUzNTg4NDEyNjQ3MDAw error="Get \"http://127.0.0.1:1/bucket30/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11432026/10/07 06:13:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzA1MjdmNTEtNWRkZC00ZGVmLTg4MjAtMTVlNTZiMWQ4NDkzLjQ5YTk0MzUyLTJlYjItNDNhNS1hMDk5LTZmMDVlOWZlMTM3MHgxNzkxMzUzNTg4MzUyMjUzMDAw parts=1211442026/10/07 06:13:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11452026/10/07 06:13:10 INFO Aborted multipart uploads count=1 kept=01146--- PASS: TestRedundantMultipartUpload (12.58s)1147=== CONT TestGCTaskStore_GetReturnsLatest1148--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1149=== CONT TestOrphanedObjectsGC11502026/10/07 06:13:11 INFO Aborted multipart uploads count=0 kept=011512026/10/07 06:13:11 WARN Force mode enabled - objects will be deleted immediately without grace period11522026/10/07 06:13:11 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/07 06:13:11 INFO Vacuumed table table=pending_closures11542026/10/07 06:13:11 INFO Vacuumed table table=pending_objects11552026/10/07 06:13:11 INFO Vacuumed table table=multipart_uploads11562026/10/07 06:13:11 INFO Vacuumed table table=closures11572026/10/07 06:13:11 INFO Vacuumed table table=objects11582026/10/07 06:13:11 INFO Aborted multipart uploads count=0 kept=011592026/10/07 06:13:11 WARN Force mode enabled - objects will be deleted immediately without grace period11602026/10/07 06:13:11 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=011612026/10/07 06:13:11 INFO Vacuumed table table=pending_closures11622026/10/07 06:13:11 INFO Vacuumed table table=pending_objects11632026/10/07 06:13:11 INFO Vacuumed table table=multipart_uploads11642026/10/07 06:13:11 INFO Vacuumed table table=closures11652026/10/07 06:13:11 INFO Received uploads request method=POST path=/api/pending_closures11662026/10/07 06:13:11 INFO Vacuumed table table=objects1167--- PASS: TestSweepSkipsRowsLockedByPush (8.68s)1168=== CONT TestGCTaskStore_GetEmpty1169--- PASS: TestGCTaskStore_GetEmpty (0.00s)1170=== CONT TestObjectStatsLargeCommit11712026/10/07 06:13:11 INFO Aborted multipart uploads count=0 kept=011722026/10/07 06:13:11 WARN Force mode enabled - objects will be deleted immediately without grace period11732026/10/07 06:13:11 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11742026/10/07 06:13:11 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1175--- PASS: TestFailedS3DeleteKeepsTombstone (8.58s)1176=== CONT TestGCTaskStore_ConflictDifferentParams1177--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1178=== CONT TestObjectStatsTrigger11792026/10/07 06:13:11 INFO Received uploads request method=POST path=/api/pending_closures1180--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (8.89s)1181=== CONT TestClientErrorHandling1182=== RUN TestClientErrorHandling/InvalidStorePath1183=== PAUSE TestClientErrorHandling/InvalidStorePath1184=== RUN TestClientErrorHandling/InvalidAuthToken1185=== PAUSE TestClientErrorHandling/InvalidAuthToken1186=== RUN TestClientErrorHandling/ServerNotAvailable1187=== PAUSE TestClientErrorHandling/ServerNotAvailable1188=== CONT TestGCTaskStore_DeduplicateSameParams1189--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1190=== CONT TestPendingCleanupUsesOneCutoff11912026/10/07 06:13:12 INFO Aborted multipart uploads count=0 kept=011922026/10/07 06:13:12 WARN Force mode enabled - objects will be deleted immediately without grace period11932026/10/07 06:13:12 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=011942026/10/07 06:13:12 INFO Vacuumed table table=pending_closures11952026/10/07 06:13:12 INFO Vacuumed table table=pending_objects11962026/10/07 06:13:12 INFO Vacuumed table table=multipart_uploads11972026/10/07 06:13:12 INFO Vacuumed table table=closures11982026/10/07 06:13:12 INFO Received uploads request method=POST path=/api/pending_closures11992026/10/07 06:13:12 INFO Vacuumed table table=objects1200--- PASS: TestGCSweepDeliversEachKeyOnce (9.13s)1201=== CONT TestGCTaskStore_StartNew1202--- PASS: TestGCTaskStore_StartNew (0.00s)1203=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1204--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.68s)1205=== CONT TestMultipartCleanup12062026/10/07 06:13:12 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/07 06:13:12 INFO Aborted multipart uploads count=0 kept=012082026/10/07 06:13:12 WARN Force mode enabled - objects will be deleted immediately without grace period12092026/10/07 06:13:12 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=012102026/10/07 06:13:12 INFO Vacuumed table table=pending_closures12112026/10/07 06:13:12 INFO Vacuumed table table=pending_objects12122026/10/07 06:13:12 INFO Vacuumed table table=multipart_uploads12132026/10/07 06:13:12 INFO Vacuumed table table=closures12142026/10/07 06:13:12 INFO Vacuumed table table=objects1215--- PASS: TestGCSweepSkipsPendingObjects (9.01s)1216=== CONT TestPush_RepeatedRootCommitsOnce12172026/10/07 06:13:13 INFO Received uploads request method=POST path=/api/pending_closures1218--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.86s)1219=== CONT TestServerTLSConfig1220=== RUN TestServerTLSConfig/no_client_CA1221=== PAUSE TestServerTLSConfig/no_client_CA1222=== RUN TestServerTLSConfig/missing_CA_file1223=== PAUSE TestServerTLSConfig/missing_CA_file1224=== RUN TestServerTLSConfig/not_a_PEM_file1225=== PAUSE TestServerTLSConfig/not_a_PEM_file1226=== CONT TestService_NativeMTLS12272026/10/07 06:13:13 INFO Received uploads request method=POST path=/api/pending_closures12282026/10/07 06:13:13 INFO Aborted multipart uploads count=0 kept=012292026/10/07 06:13:13 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=012302026/10/07 06:13:13 INFO Vacuumed table table=pending_closures12312026/10/07 06:13:13 INFO Aborted multipart uploads count=0 kept=012322026/10/07 06:13:13 INFO Vacuumed table table=pending_objects12332026/10/07 06:13:13 INFO Vacuumed table table=multipart_uploads12342026/10/07 06:13:13 WARN Force mode enabled - objects will be deleted immediately without grace period12352026/10/07 06:13:13 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=012362026/10/07 06:13:13 INFO Vacuumed table table=closures12372026/10/07 06:13:13 INFO Vacuumed table table=pending_closures12382026/10/07 06:13:13 INFO Vacuumed table table=pending_objects12392026/10/07 06:13:13 INFO Vacuumed table table=multipart_uploads12402026/10/07 06:13:13 INFO Vacuumed table table=objects12412026/10/07 06:13:13 INFO Vacuumed table table=closures12422026/10/07 06:13:13 INFO Vacuumed table table=objects1243--- PASS: TestGCMetrics (9.02s)1244=== CONT TestMetricsCommit12452026/10/07 06:13:13 INFO Aborted multipart uploads count=0 kept=012462026/10/07 06:13:13 WARN Force mode enabled - objects will be deleted immediately without grace period12472026/10/07 06:13:13 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=012482026/10/07 06:13:13 INFO Vacuumed table table=pending_closures12492026/10/07 06:13:13 INFO Vacuumed table table=pending_objects12502026/10/07 06:13:13 INFO Vacuumed table table=multipart_uploads12512026/10/07 06:13:13 INFO Vacuumed table table=closures12522026/10/07 06:13:13 INFO Vacuumed table table=objects1253--- PASS: TestPushDedupSurvivesConcurrentGC (9.41s)1254=== CONT TestService_RequireScope_OIDC12552026/10/07 06:13:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52648/oidc12562026/10/07 06:13:14 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld6 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1257--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (8.91s)1258=== CONT TestClientCADerivations1259--- PASS: TestGCBugBareHashReferences (9.39s)1260=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12612026/10/07 06:13:14 INFO lead: acquired remote=192.0.2.1:123412622026/10/07 06:13:14 INFO lead: acquired remote=192.0.2.1:123412632026/10/07 06:13:14 INFO lead: released remote=192.0.2.1:12341264--- PASS: TestLeadIncumbentAnnouncesAtOnce (8.20s)1265=== CONT TestCacheStatsHandler12662026/10/07 06:13:14 INFO lead: acquired remote=192.0.2.1:123412672026/10/07 06:13:15 WARN readiness check failed error="closed pool"1268--- PASS: TestService_readinessHandler (7.07s)1269=== CONT TestCacheConfigHandler1270=== RUN TestCacheConfigHandler/full_config,_no_issuer1271=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1272=== RUN TestCacheConfigHandler/no_cache_url_configured1273=== PAUSE TestCacheConfigHandler/no_cache_url_configured1274=== RUN TestCacheConfigHandler/no_signing_keys1275=== PAUSE TestCacheConfigHandler/no_signing_keys1276=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1277=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1278=== CONT TestService_ReadScope_PublicByDefault1279=== NAME TestNARDeduplicationMetadataUploadBug1280 metadata_upload_test.go:48: First store path: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestNARDeduplicationMetadataUploadBug1136321502/001/store/zd6bp7gqmnig0npc49js29ni20wlcz8h-file1.txt12812026/10/07 06:13:15 INFO lead: released remote=192.0.2.1:12341282--- PASS: TestLeadEndsOnShutdown (9.59s)1283=== CONT TestPinProtectsFromGC12842026/10/07 06:13:15 INFO Received push request method=POST path=/api/pushes12852026/10/07 06:13:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12862026/10/07 06:13:15 INFO Uploading zd6bp7gqmnig0npc49js29ni20wlcz8h-file1.txt (160B)12872026/10/07 06:13:15 WARN Failed to register uploaded object key=zd6bp7gqmnig0npc49js29ni20wlcz8h.ls error="server returned 404: 404 page not found\n"12882026/10/07 06:13:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/07 06:13:15 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12902026/10/07 06:13:15 INFO Signed narinfos id=1 count=112912026/10/07 06:13:15 INFO Uploading 1 narinfos1292--- PASS: TestService_healthCheckHandler (6.40s)1293=== CONT TestDeleteClosuresRacingPins12942026/10/07 06:13:15 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026/10/07 06:13:15 WARN Failed to register uploaded object key=zd6bp7gqmnig0npc49js29ni20wlcz8h.narinfo error="server returned 404: 404 page not found\n"12962026/10/07 06:13:15 INFO Completed push id=1 objects=3 duration=21.842416ms12972026/10/07 06:13:15 INFO Upload complete. (176ms)1298=== NAME TestNARDeduplicationMetadataUploadBug1299 metadata_upload_test.go:54: Retrieved narinfo from S3:1300 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestNARDeduplicationMetadataUploadBug1136321502/001/store/zd6bp7gqmnig0npc49js29ni20wlcz8h-file1.txt1301 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1302 Compression: zstd1303 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1304 NarSize: 1601305 References: 1306 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1307 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1308 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1309 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1310 metadata_upload_test.go:64: Second store path (same content): /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestNARDeduplicationMetadataUploadBug1136321502/001/store/qvjyndw53i94ylkmhzmn0d5gkf37d55v-file2.txt13112026/10/07 06:13:15 INFO Received push request method=POST path=/api/pushes13122026/10/07 06:13:15 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1313--- PASS: TestPresentRefreshesOnlyStaleClosures (6.26s)1314=== CONT TestClientSharedPathCommittedMidPush13152026/10/07 06:13:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13162026/10/07 06:13:15 INFO Signed narinfos id=2 count=113172026/10/07 06:13:15 WARN Failed to register uploaded object key=qvjyndw53i94ylkmhzmn0d5gkf37d55v.ls error="server returned 404: 404 page not found\n"13182026/10/07 06:13:15 INFO Uploading 1 narinfos13192026/10/07 06:13:16 INFO Received complete push request method=POST path=/api/pushes/2/complete13202026/10/07 06:13:16 WARN Failed to register uploaded object key=qvjyndw53i94ylkmhzmn0d5gkf37d55v.narinfo error="server returned 404: 404 page not found\n"13212026/10/07 06:13:16 INFO Completed push id=2 objects=3 duration=875.375µs13222026/10/07 06:13:16 INFO Upload complete. (142ms)1323=== NAME TestNARDeduplicationMetadataUploadBug1324 metadata_upload_test.go:76: Retrieved narinfo from S3:1325 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestNARDeduplicationMetadataUploadBug1136321502/001/store/qvjyndw53i94ylkmhzmn0d5gkf37d55v-file2.txt1326 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1327 Compression: zstd1328 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1329 NarSize: 1601330 References: 1331 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1332 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1333 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1334 {"version":1,"root":{"type":"regular","size":44}}1335--- PASS: TestNARDeduplicationMetadataUploadBug (7.83s)13362026/10/07 06:13:16 INFO lead: released remote=192.0.2.1:12341337=== CONT TestClientFallsBackToClosures13382026/10/07 06:13:16 INFO lead: acquired remote=192.0.2.1:12341339--- PASS: TestMetricsInventory (6.71s)1340=== CONT TestClientIntegration1341--- PASS: TestPresentReportsOnlyClosureRoots (6.50s)1342=== CONT TestClientPushesUseOnePush13432026/10/07 06:13:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13442026/10/07 06:13:16 WARN Refused reserved pin name=worker-x86_64-linux13452026/10/07 06:13:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13462026/10/07 06:13:16 INFO Received create pin request method=POST path=/api/pins/my-app13472026/10/07 06:13:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1348--- PASS: TestCreatePin_ReservedPins (6.61s)1349=== CONT TestClientMultipleUploads1350--- PASS: TestConnectWaitsForAPeerMigration (8.90s)1351=== CONT TestService_ReadAuthMiddleware13522026/10/07 06:13:17 INFO lead: released remote=192.0.2.1:12341353--- PASS: TestLeadElectsOneAndHandsOver (9.69s)1354=== CONT TestClientWithDependencies1355=== NAME TestOrphanedObjectsGC1356 orphaned_objects_gc_test.go:287: GC Test Summary:1357 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1358 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1359 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1360 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1361 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1362--- PASS: TestOrphanedObjectsGC (7.71s)1363=== CONT TestService_AuthMiddleware_OIDC13642026/10/07 06:13:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52693/oidc1365--- PASS: TestObjectStatsTrigger (7.18s)1366=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13672026/10/07 06:13:19 INFO Received uploads request method=POST path=/api/pending_closures13682026/10/07 06:13:19 INFO Received uploads request method=POST path=/api/pending_closures13692026/10/07 06:13:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13702026/10/07 06:13:19 INFO Received uploads request method=POST path=/api/pending_closures13712026/10/07 06:13:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13722026/10/07 06:13:19 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket69/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13732026/10/07 06:13:19 INFO Aborted multipart uploads count=0 kept=113742026/10/07 06:13:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13752026/10/07 06:13:19 INFO Aborted multipart uploads count=1 kept=01376--- PASS: TestMultipartCleanup (7.58s)1377=== CONT TestService_AuthMiddleware_MTLSProxyHeader13782026/10/07 06:13:20 INFO Received uploads request method=POST path=/api/pending_closures1379--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.87s)1380=== CONT TestProxyWriteTimeout/narinfo1381=== CONT TestProxyWriteTimeout/unknown_size1382=== CONT TestProxyWriteTimeout/10_GiB_nar1383=== CONT TestProxyWriteTimeout/1_GiB_nar1384--- PASS: TestProxyWriteTimeout (0.05s)1385 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1386 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1387 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1388 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1389=== CONT TestGCEndsOnShutdown/before_the_run13902026/10/07 06:13:20 INFO Received push request method=POST path=/api/pushes13912026/10/07 06:13:20 INFO Received complete push request method=POST path=/api/pushes/1/complete13922026/10/07 06:13:20 INFO Completed push id=1 objects=4 duration=61.176708ms1393--- PASS: TestPush_RepeatedRootCommitsOnce (7.83s)1394=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark13952026/10/07 06:13:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13962026/10/07 06:13:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1397--- PASS: TestService_NativeMTLS (7.96s)1398=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete13992026/10/07 06:13:21 INFO Received push request method=POST path=/api/pushes14002026/10/07 06:13:21 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/10/07 06:13:21 INFO Completed push id=1 objects=4 duration=56.080583ms14022026/10/07 06:13:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14032026/10/07 06:13:21 INFO Completed upload id=2 objects=2 duration=1.390708ms1404--- PASS: TestMetricsCommit (8.08s)1405=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14062026/10/07 06:13:21 INFO Received uploads request method=POST path=/1407=== RUN TestService_RequireScope_OIDC/builder_may_write1408=== PAUSE TestService_RequireScope_OIDC/builder_may_write1409=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1410=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1411=== RUN TestService_RequireScope_OIDC/ops_may_admin1412=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1413=== RUN TestService_RequireScope_OIDC/ops_may_not_write1414=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1415=== RUN TestService_RequireScope_OIDC/reader_may_not_write1416=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1417=== RUN TestService_RequireScope_OIDC/static_token_may_admin1418=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1419=== RUN TestService_RequireScope_OIDC/static_token_may_write1420=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1421=== RUN TestService_RequireScope_OIDC/reader_may_read1422=== PAUSE TestService_RequireScope_OIDC/reader_may_read1423=== RUN TestService_RequireScope_OIDC/writer_implies_read1424=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1425=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1426=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1427=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1428=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1429=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1430=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1431=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1432=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1433=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1434=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1435=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14362026/10/07 06:13:22 INFO Received request for more parts method=POST path=/1437=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14382026/10/07 06:13:22 INFO Received complete multipart upload request method=POST path=/1439=== CONT TestIsValidCachePath/narinfo1440=== CONT TestIsValidCachePath/index.html1441=== CONT TestIsValidCachePath/short_hash1442=== CONT TestIsValidCachePath/wrong_extension1443=== CONT TestIsValidCachePath/leading_slash1444=== CONT TestIsValidCachePath/empty1445=== CONT TestIsValidCachePath/random_path1446=== CONT TestIsValidCachePath/invalid_char_u1447=== CONT TestIsValidCachePath/invalid_char_e1448=== CONT TestIsValidCachePath/traversal_in_middle1449=== CONT TestIsValidCachePath/traversal_parent1450=== CONT TestIsValidCachePath/nar_uncompressed1451=== CONT TestIsValidCachePath/nix-cache-info1452=== CONT TestIsValidCachePath/realisation1453=== CONT TestIsValidCachePath/log1454=== CONT TestIsValidCachePath/ls1455=== CONT TestIsValidCachePath/nar_xz1456=== CONT TestIsValidCachePath/nar_bz21457=== CONT TestIsValidCachePath/nar_zst1458=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1459--- PASS: TestIsValidCachePath (0.00s)1460 --- PASS: TestIsValidCachePath/narinfo (0.00s)1461 --- PASS: TestIsValidCachePath/index.html (0.00s)1462 --- PASS: TestIsValidCachePath/short_hash (0.00s)1463 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1464 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1465 --- PASS: TestIsValidCachePath/empty (0.00s)1466 --- PASS: TestIsValidCachePath/random_path (0.00s)1467 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1468 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1469 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1470 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1471 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1472 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1473 --- PASS: TestIsValidCachePath/realisation (0.00s)1474 --- PASS: TestIsValidCachePath/log (0.00s)1475 --- PASS: TestIsValidCachePath/ls (0.00s)1476 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1477 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1478 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1479 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1480=== CONT TestPendingClosureWriteTimeout/empty1481=== CONT TestPendingClosureWriteTimeout/670k_objects1482=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1483--- PASS: TestUploadHandlersRejectOversizedBody (0.11s)1484 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1485 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1486 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.36s)1487=== CONT TestPendingClosureWriteTimeout/400_objects1488=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14892026/10/07 06:13:22 INFO Received uploads request method=POST path=/1490=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14912026/10/07 06:13:22 INFO Received complete multipart upload request method=POST path=/1492=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14932026/10/07 06:13:22 INFO Received request for more parts method=POST path=/1494=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14952026/10/07 06:13:22 INFO Received uploads request method=POST path=/1496--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1497 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1498 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)1499 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.01s)1500 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)1501=== CONT TestIsValidUploadKey/narinfo1502=== CONT TestIsValidUploadKey/realisation_plus_in_output1503=== CONT TestIsValidUploadKey/unknown_type1504=== CONT TestIsValidUploadKey/empty_key1505=== CONT TestIsValidUploadKey/absolute1506=== CONT TestIsValidUploadKey/traversal_nar1507=== CONT TestIsValidUploadKey/traversal1508=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1509=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1510=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1511=== CONT TestIsValidUploadKey/index.html1512=== CONT TestIsValidUploadKey/nix-cache-info1513=== CONT TestIsValidUploadKey/build_log_home-manager_file1514=== CONT TestIsValidUploadKey/realisation1515=== CONT TestIsValidUploadKey/build_log_equals1516=== CONT TestIsValidUploadKey/build_log_question_mark1517=== CONT TestIsValidUploadKey/build_log_plus_in_name1518=== CONT TestIsValidUploadKey/nar_plain1519=== CONT TestIsValidUploadKey/build_log1520=== CONT TestIsValidUploadKey/listing1521=== CONT TestIsValidUploadKey/nar_xz1522=== CONT TestIsValidUploadKey/nar_zst1523--- PASS: TestIsValidUploadKey (0.01s)1524 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1525 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1526 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1527 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1528 --- PASS: TestIsValidUploadKey/absolute (0.00s)1529 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1530 --- PASS: TestIsValidUploadKey/traversal (0.00s)1531 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1532 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1533 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1534 --- PASS: TestIsValidUploadKey/index.html (0.00s)1535 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1536 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1537 --- PASS: TestIsValidUploadKey/realisation (0.00s)1538 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1539 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1540 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1541 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1542 --- PASS: TestIsValidUploadKey/build_log (0.00s)1543 --- PASS: TestIsValidUploadKey/listing (0.00s)1544 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1545 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1546=== CONT TestResolveDBConnectionString/flag_wins1547=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1548=== CONT TestResolveDBConnectionString/nothing_configured1549=== CONT TestResolveDBConnectionString/missing_file_is_an_error1550=== CONT TestResolveDBConnectionString/file_when_flag_empty1551=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1552--- PASS: TestResolveDBConnectionString (0.02s)1553 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1554 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1555 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1556 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1557 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1558=== NAME TestClientCADerivations1559 client_ca_test.go:136: Built CA derivation: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientCADerivations1289701922/001/store/gkkza429aqkahwd1hkgn3c39n0v7m9rf-ca-test1560 client_ca_test.go:139: Found 1 dependencies (including self)1561--- PASS: TestCacheStatsHandler (8.61s)1562=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15632026/10/07 06:13:23 INFO Received push request method=POST path=/api/pushes1564--- PASS: TestService_ReadScope_PublicByDefault (8.09s)1565=== CONT TestParseSingleRange/none1566=== CONT TestParseSingleRange/open-ended1567=== CONT TestParseSingleRange/start_far_past_EOF1568=== CONT TestParseSingleRange/start_past_EOF1569=== CONT TestParseSingleRange/single_byte1570=== CONT TestParseSingleRange/suffix_exceeds_size1571=== CONT TestParseSingleRange/suffix1572=== CONT TestParseSingleRange/end_clamped_to_size1573=== CONT TestParseSingleRange/malformed_both_empty1574=== CONT TestParseSingleRange/closed1575=== CONT TestParseSingleRange/malformed_end_before_start1576=== CONT TestParseSingleRange/multi-range_ignored15772026/10/07 06:13:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1578=== CONT TestParseSingleRange/malformed_no_dash1579=== CONT TestParseSingleRange/unknown_unit1580--- PASS: TestParseSingleRange (0.02s)1581 --- PASS: TestParseSingleRange/none (0.00s)1582 --- PASS: TestParseSingleRange/open-ended (0.00s)1583 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1584 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1585 --- PASS: TestParseSingleRange/single_byte (0.00s)1586 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1587 --- PASS: TestParseSingleRange/suffix (0.00s)1588 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1589 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1590 --- PASS: TestParseSingleRange/closed (0.00s)1591 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1592 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1593 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1594 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1595=== CONT TestPush_RejectsBadRequests/no_roots15962026/10/07 06:13:23 INFO Uploading gkkza429aqkahwd1hkgn3c39n0v7m9rf-ca-test (144B)15972026/10/07 06:13:23 INFO Received push request method=POST path=/api/pushes1598=== CONT TestPush_RejectsBadRequests/bad_root15992026/10/07 06:13:23 INFO Received push request method=POST path=/api/pushes1600=== CONT TestPush_RejectsBadRequests/no_objects16012026/10/07 06:13:23 INFO Received push request method=POST path=/api/pushes1602=== CONT TestPush_RejectsBadRequests/root_not_in_objects16032026/10/07 06:13:23 INFO Received push request method=POST path=/api/pushes1604=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1605--- PASS: TestPush_RejectsBadRequests (7.65s)1606 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1607 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1608 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1609 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)16102026/10/07 06:13:23 WARN Failed to register uploaded object key=gkkza429aqkahwd1hkgn3c39n0v7m9rf.ls error="server returned 404: 404 page not found\n"16112026/10/07 06:13:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16122026/10/07 06:13:23 WARN Failed to register uploaded object key=log/94mkpalkyji8wg050prlj83wkfa81rim-ca-test.drv error="server returned 404: 404 page not found\n"16132026/10/07 06:13:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16142026/10/07 06:13:23 INFO Signed narinfos id=1 count=116152026/10/07 06:13:23 INFO Uploading 1 narinfos16162026/10/07 06:13:23 INFO Received complete push request method=POST path=/api/pushes/1/complete16172026/10/07 06:13:23 WARN Failed to register uploaded object key=gkkza429aqkahwd1hkgn3c39n0v7m9rf.narinfo error="server returned 404: 404 page not found\n"16182026/10/07 06:13:23 INFO Completed push id=1 objects=4 duration=41.104291ms16192026/10/07 06:13:23 INFO Upload complete. (375ms)1620=== NAME TestClientCADerivations1621 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientCADerivations1289701922/001/store/gkkza429aqkahwd1hkgn3c39n0v7m9rf-ca-test1622 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1623 Compression: zstd1624 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1625 NarSize: 1441626 References: 1627 Deriver: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientCADerivations1289701922/001/store/94mkpalkyji8wg050prlj83wkfa81rim-ca-test.drv1628 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1629 client_ca_test.go:185: Checking for realisation files in S3...1630 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1631 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1632 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket75?endpoint=http://localhost:52402®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientCADerivations1289701922/001/store'1633 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11634--- PASS: TestClientCADerivations (9.88s)1635=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1636=== NAME TestPinProtectsFromGC1637 client_integration_test.go:731: Pinned store path: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestPinProtectsFromGC4234992708/001/store/cd2agqhpyqx5gfxm804573y4syykhxl6-pinned-file.txt1638 client_integration_test.go:732: Unpinned store path: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestPinProtectsFromGC4234992708/001/store/bfw2lfc3j158xpnfsx7rkcip45xy3z4z-unpinned-file.txt1639--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.23s)1640=== CONT TestClientErrorHandling/InvalidStorePath16412026/10/07 06:13:24 INFO Received push request method=POST path=/api/pushes16422026/10/07 06:13:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16432026/10/07 06:13:24 INFO Uploading cd2agqhpyqx5gfxm804573y4syykhxl6-pinned-file.txt (128B)16442026/10/07 06:13:24 WARN Failed to register uploaded object key=cd2agqhpyqx5gfxm804573y4syykhxl6.ls error="server returned 404: 404 page not found\n"16452026/10/07 06:13:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16462026/10/07 06:13:24 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16472026/10/07 06:13:24 INFO Signed narinfos id=1 count=116482026/10/07 06:13:24 INFO Uploading 1 narinfos16492026/10/07 06:13:24 INFO Received complete push request method=POST path=/api/pushes/1/complete16502026/10/07 06:13:24 WARN Failed to register uploaded object key=cd2agqhpyqx5gfxm804573y4syykhxl6.narinfo error="server returned 404: 404 page not found\n"16512026/10/07 06:13:24 INFO Completed push id=1 objects=3 duration=43.164125ms16522026/10/07 06:13:24 INFO Upload complete. (230ms)16532026/10/07 06:13:24 INFO Received push request method=POST path=/api/pushes16542026/10/07 06:13:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16552026/10/07 06:13:24 INFO Uploading bfw2lfc3j158xpnfsx7rkcip45xy3z4z-unpinned-file.txt (128B)16562026/10/07 06:13:24 WARN Failed to register uploaded object key=bfw2lfc3j158xpnfsx7rkcip45xy3z4z.ls error="server returned 404: 404 page not found\n"16572026/10/07 06:13:24 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16582026/10/07 06:13:24 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16592026/10/07 06:13:24 INFO Signed narinfos id=2 count=116602026/10/07 06:13:24 INFO Uploading 1 narinfos16612026/10/07 06:13:24 INFO Received complete push request method=POST path=/api/pushes/2/complete16622026/10/07 06:13:24 WARN Failed to register uploaded object key=bfw2lfc3j158xpnfsx7rkcip45xy3z4z.narinfo error="server returned 404: 404 page not found\n"16632026/10/07 06:13:24 INFO Completed push id=2 objects=3 duration=922.667µs16642026/10/07 06:13:24 INFO Upload complete. (210ms)16652026/10/07 06:13:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16662026/10/07 06:13:25 INFO Garbage collection started16672026/10/07 06:13:25 INFO Aborted multipart uploads count=0 kept=016682026/10/07 06:13:25 WARN Force mode enabled - objects will be deleted immediately without grace period16692026/10/07 06:13:25 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=016702026/10/07 06:13:25 INFO Vacuumed table table=pending_closures16712026/10/07 06:13:25 INFO Vacuumed table table=pending_objects16722026/10/07 06:13:25 INFO Received push request method=POST path=/api/pushes16732026/10/07 06:13:25 INFO Vacuumed table table=multipart_uploads16742026/10/07 06:13:25 INFO Aborted multipart uploads count=1 kept=016752026/10/07 06:13:25 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16762026/10/07 06:13:25 INFO Uploading p396pm0ygx9q6ardi8xfsskhpzgzgqn3-shared-dep (136B)16772026/10/07 06:13:25 INFO Uploading 5kfwprgny524ah63ki7fikqsphdlww8c-top (280B)16782026/10/07 06:13:25 INFO Vacuumed table table=closures16792026/10/07 06:13:25 INFO Received cleanup request method=DELETE path=/api/pending_closures16802026/10/07 06:13:25 WARN Failed to register uploaded object key=p396pm0ygx9q6ardi8xfsskhpzgzgqn3.ls error="server returned 404: 404 page not found\n"16812026/10/07 06:13:25 INFO Vacuumed table table=objects16822026/10/07 06:13:25 INFO Aborted multipart uploads count=1 kept=016832026/10/07 06:13:25 WARN Failed to register uploaded object key=5kfwprgny524ah63ki7fikqsphdlww8c.ls error="server returned 404: 404 page not found\n"1684--- PASS: TestPendingCleanupUsesOneCutoff (13.53s)16852026/10/07 06:13:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1686=== CONT TestClientErrorHandling/ServerNotAvailable16872026/10/07 06:13:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16882026/10/07 06:13:25 WARN Failed to register uploaded object key=nar/14fxaxvz5lick2z83zl5h0bd7s8vs7xqxd3nrk2pbynb4x1lkwgl.nar.zst error="server returned 404: 404 page not found\n"16892026/10/07 06:13:25 INFO Signed narinfos id=1 count=216902026/10/07 06:13:25 INFO Uploading 2 narinfos16912026/10/07 06:13:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16922026/10/07 06:13:25 WARN Failed to register uploaded object key=5kfwprgny524ah63ki7fikqsphdlww8c.narinfo error="server returned 404: 404 page not found\n"16932026/10/07 06:13:25 WARN Failed to register uploaded object key=p396pm0ygx9q6ardi8xfsskhpzgzgqn3.narinfo error="server returned 404: 404 page not found\n"16942026/10/07 06:13:25 INFO Completed push id=1 objects=6 duration=39.909542ms16952026/10/07 06:13:25 INFO Upload complete. (328ms)1696=== NAME TestClientSharedPathCommittedMidPush1697 client_integration_test.go:680: Retrieved narinfo from S3:1698 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientSharedPathCommittedMidPush2214890470/001/store/p396pm0ygx9q6ardi8xfsskhpzgzgqn3-shared-dep1699 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1700 Compression: zstd1701 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821702 NarSize: 1361703 References: 1704 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1705 client_integration_test.go:680: Retrieved narinfo from S3:1706 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientSharedPathCommittedMidPush2214890470/001/store/5kfwprgny524ah63ki7fikqsphdlww8c-top1707 URL: nar/14fxaxvz5lick2z83zl5h0bd7s8vs7xqxd3nrk2pbynb4x1lkwgl.nar.zst1708 Compression: zstd1709 NarHash: sha256:14fxaxvz5lick2z83zl5h0bd7s8vs7xqxd3nrk2pbynb4x1lkwgl1710 NarSize: 2801711 References: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientSharedPathCommittedMidPush2214890470/001/store/p396pm0ygx9q6ardi8xfsskhpzgzgqn3-shared-dep1712 CA: text:sha256:165prmfazjsqqnv33dg2fhms95ys1ym8msxxw5jnlp1d9bb35qwm1713--- PASS: TestClientSharedPathCommittedMidPush (9.67s)1714=== CONT TestClientErrorHandling/InvalidAuthToken1715=== NAME TestClientIntegration1716 client_integration_test.go:286: Created store path: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientIntegration2724788684/002/store/5g6dx24v45niia2vak4jng805sqqzk4d-test-file.txt17172026/10/07 06:13:25 INFO Received uploads request method=POST path=/api/pending_closures17182026/10/07 06:13:25 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17192026/10/07 06:13:25 INFO Received uploads request method=POST path=/api/pending_closures17202026/10/07 06:13:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17212026/10/07 06:13:25 INFO Uploading 6cp7s48bmxh4l8av35zimbdifv0lyqq9-b (272B)17222026/10/07 06:13:25 INFO Uploading ba7v1drh44an0njvfr8k942y2sdfzw7g-shared-dep (136B)17232026/10/07 06:13:25 WARN Failed to register uploaded object key=4y35qi3ajqgific5y5fc5hk8rcfddfwq.ls error="server returned 404: 404 page not found\n"17242026/10/07 06:13:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17252026/10/07 06:13:25 WARN Failed to register uploaded object key=ba7v1drh44an0njvfr8k942y2sdfzw7g.ls error="server returned 404: 404 page not found\n"17262026/10/07 06:13:25 WARN Failed to register uploaded object key=nar/0msqvv0m4gbjc4k1lawbpqc2y9glpw1n6b25c8zkgbnwrvnz9ha3.nar.zst error="server returned 404: 404 page not found\n"17272026/10/07 06:13:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17282026/10/07 06:13:25 WARN Failed to register uploaded object key=6cp7s48bmxh4l8av35zimbdifv0lyqq9.ls error="server returned 404: 404 page not found\n"17292026/10/07 06:13:25 INFO Signed narinfos id=1 count=217302026/10/07 06:13:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17312026/10/07 06:13:25 INFO Signed narinfos id=2 count=217322026/10/07 06:13:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.008498ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17332026/10/07 06:13:25 INFO Uploading 4 narinfos17342026/10/07 06:13:25 INFO Received push request method=POST path=/api/pushes17352026/10/07 06:13:26 WARN Failed to register uploaded object key=4y35qi3ajqgific5y5fc5hk8rcfddfwq.narinfo error="server returned 404: 404 page not found\n"17362026/10/07 06:13:26 WARN Failed to register uploaded object key=6cp7s48bmxh4l8av35zimbdifv0lyqq9.narinfo error="server returned 404: 404 page not found\n"17372026/10/07 06:13:26 WARN Failed to register uploaded object key=ba7v1drh44an0njvfr8k942y2sdfzw7g.narinfo error="server returned 404: 404 page not found\n"17382026/10/07 06:13:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17392026/10/07 06:13:26 INFO Uploading 5g6dx24v45niia2vak4jng805sqqzk4d-test-file.txt (152B)17402026/10/07 06:13:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17412026/10/07 06:13:26 WARN Failed to register uploaded object key=ba7v1drh44an0njvfr8k942y2sdfzw7g.narinfo error="server returned 404: 404 page not found\n"17422026/10/07 06:13:26 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17432026/10/07 06:13:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17442026/10/07 06:13:26 WARN Failed to register uploaded object key=5g6dx24v45niia2vak4jng805sqqzk4d.ls error="server returned 404: 404 page not found\n"17452026/10/07 06:13:26 INFO Completed upload id=1 objects=6 duration=25.926125ms17462026/10/07 06:13:26 INFO Signed narinfos id=1 count=117472026/10/07 06:13:26 INFO Uploading 1 narinfos17482026/10/07 06:13:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17492026/10/07 06:13:26 INFO Completed upload id=2 objects=6 duration=591.667µs17502026/10/07 06:13:26 INFO Upload complete. (341ms)1751=== NAME TestClientFallsBackToClosures1752 client_pushes_test.go:112: Retrieved narinfo from S3:1753 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientFallsBackToClosures3992341817/001/store/ba7v1drh44an0njvfr8k942y2sdfzw7g-shared-dep1754 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1755 Compression: zstd1756 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821757 NarSize: 1361758 References: 1759 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17602026/10/07 06:13:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17612026/10/07 06:13:26 WARN Failed to register uploaded object key=5g6dx24v45niia2vak4jng805sqqzk4d.narinfo error="server returned 404: 404 page not found\n"1762 client_pushes_test.go:112: Retrieved narinfo from S3:1763 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientFallsBackToClosures3992341817/001/store/4y35qi3ajqgific5y5fc5hk8rcfddfwq-a1764 URL: nar/0msqvv0m4gbjc4k1lawbpqc2y9glpw1n6b25c8zkgbnwrvnz9ha3.nar.zst1765 Compression: zstd1766 NarHash: sha256:0msqvv0m4gbjc4k1lawbpqc2y9glpw1n6b25c8zkgbnwrvnz9ha31767 NarSize: 2721768 References: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientFallsBackToClosures3992341817/001/store/ba7v1drh44an0njvfr8k942y2sdfzw7g-shared-dep1769 CA: text:sha256:0z4gi4l3bfqwrlgsa4gv6zbpf65pb77rqxp9snq07rn9ylgsqa7y1770 client_pushes_test.go:112: Retrieved narinfo from S3:1771 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientFallsBackToClosures3992341817/001/store/6cp7s48bmxh4l8av35zimbdifv0lyqq9-b1772 URL: nar/0msqvv0m4gbjc4k1lawbpqc2y9glpw1n6b25c8zkgbnwrvnz9ha3.nar.zst1773 Compression: zstd1774 NarHash: sha256:0msqvv0m4gbjc4k1lawbpqc2y9glpw1n6b25c8zkgbnwrvnz9ha31775 NarSize: 2721776 References: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientFallsBackToClosures3992341817/001/store/ba7v1drh44an0njvfr8k942y2sdfzw7g-shared-dep1777 CA: text:sha256:0z4gi4l3bfqwrlgsa4gv6zbpf65pb77rqxp9snq07rn9ylgsqa7y17782026/10/07 06:13:26 INFO Completed push id=1 objects=3 duration=35.747166ms17792026/10/07 06:13:26 INFO Upload complete. (284ms)17802026/10/07 06:13:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.823872ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1781--- PASS: TestService_ReadAuthMiddleware (9.13s)1782=== CONT TestServerTLSConfig/no_client_CA1783=== CONT TestServerTLSConfig/not_a_PEM_file17842026/10/07 06:13:26 INFO All 1 paths already cached1785=== CONT TestServerTLSConfig/missing_CA_file1786--- PASS: TestServerTLSConfig (0.01s)1787 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1788 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1789 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1790=== CONT TestCacheConfigHandler/full_config,_no_issuer1791=== CONT TestCacheConfigHandler/no_signing_keys1792=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1793=== CONT TestCacheConfigHandler/no_cache_url_configured1794--- PASS: TestCacheConfigHandler (0.00s)1795 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1796 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1797 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1798 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1799=== CONT TestService_RequireScope_OIDC/builder_may_write1800--- PASS: TestClientFallsBackToClosures (10.06s)1801=== CONT TestService_RequireScope_OIDC/reader_may_read1802=== NAME TestClientIntegration1803 client_integration_test.go:312: Retrieved narinfo from S3:1804 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientIntegration2724788684/002/store/5g6dx24v45niia2vak4jng805sqqzk4d-test-file.txt1805 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1806 Compression: zstd1807 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11808 NarSize: 1521809 References: 1810 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11811=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1812=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18132026/10/07 06:13:26 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]1814=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1815=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1816=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1817=== CONT TestService_RequireScope_OIDC/writer_implies_read1818=== CONT TestService_RequireScope_OIDC/static_token_may_write1819=== CONT TestService_RequireScope_OIDC/static_token_may_admin1820=== CONT TestService_RequireScope_OIDC/ops_may_admin1821=== CONT TestService_RequireScope_OIDC/ops_may_not_write1822=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1823=== CONT TestService_RequireScope_OIDC/reader_may_not_write1824=== NAME TestClientIntegration1825 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1826 client_integration_test.go:313: Decompressed .ls content (64 bytes):1827 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1828 client_integration_test.go:316: Testing garbage collection...1829--- PASS: TestService_RequireScope_OIDC (8.25s)1830 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)18442026/10/07 06:13:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures18452026/10/07 06:13:26 INFO Garbage collection started18462026/10/07 06:13:26 INFO Aborted multipart uploads count=0 kept=018472026/10/07 06:13:26 WARN Force mode enabled - objects will be deleted immediately without grace period18482026/10/07 06:13:26 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=018492026/10/07 06:13:26 INFO Received push request method=POST path=/api/pushes18502026/10/07 06:13:26 INFO Vacuumed table table=pending_closures18512026/10/07 06:13:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18522026/10/07 06:13:26 INFO Uploading vd1gw8sngx6rfih83d00xbky3slxxm4g-shared-dep (136B)18532026/10/07 06:13:26 INFO Uploading yx3n8ydvny1yfs18ajyikm3yyv1mxpbk-a (264B)18542026/10/07 06:13:26 INFO Vacuumed table table=pending_objects18552026/10/07 06:13:26 INFO Vacuumed table table=multipart_uploads18562026/10/07 06:13:26 WARN Failed to register uploaded object key=85yc36d0mnk4x1qf81jc3z1nwq42cwlc.ls error="server returned 404: 404 page not found\n"18572026/10/07 06:13:26 WARN Failed to register uploaded object key=vd1gw8sngx6rfih83d00xbky3slxxm4g.ls error="server returned 404: 404 page not found\n"18582026/10/07 06:13:26 WARN Failed to register uploaded object key=yx3n8ydvny1yfs18ajyikm3yyv1mxpbk.ls error="server returned 404: 404 page not found\n"18592026/10/07 06:13:26 INFO Vacuumed table table=closures18602026/10/07 06:13:26 WARN Failed to register uploaded object key=nar/12a910f1k21hayqrwwn8w7ydwvpwwxa1vqp6idhar70b5b2hv3mh.nar.zst error="server returned 404: 404 page not found\n"18612026/10/07 06:13:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18622026/10/07 06:13:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18632026/10/07 06:13:26 INFO Signed narinfos id=1 count=318642026/10/07 06:13:26 INFO Uploading 3 narinfos18652026/10/07 06:13:26 INFO Vacuumed table table=objects18662026/10/07 06:13:26 WARN Failed to register uploaded object key=85yc36d0mnk4x1qf81jc3z1nwq42cwlc.narinfo error="server returned 404: 404 page not found\n"18672026/10/07 06:13:26 INFO Received complete push request method=POST path=/api/pushes/1/complete18682026/10/07 06:13:26 WARN Failed to register uploaded object key=vd1gw8sngx6rfih83d00xbky3slxxm4g.narinfo error="server returned 404: 404 page not found\n"18692026/10/07 06:13:26 WARN Failed to register uploaded object key=yx3n8ydvny1yfs18ajyikm3yyv1mxpbk.narinfo error="server returned 404: 404 page not found\n"18702026/10/07 06:13:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.899293ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18712026/10/07 06:13:26 INFO Completed push id=1 objects=8 duration=20.178583ms18722026/10/07 06:13:26 INFO Upload complete. (216ms)1873=== NAME TestClientPushesUseOnePush1874 client_pushes_test.go:97: Retrieved narinfo from S3:1875 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientPushesUseOnePush2759757726/001/store/vd1gw8sngx6rfih83d00xbky3slxxm4g-shared-dep1876 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1877 Compression: zstd1878 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821879 NarSize: 1361880 References: 1881 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1882 client_pushes_test.go:97: Retrieved narinfo from S3:1883 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientPushesUseOnePush2759757726/001/store/yx3n8ydvny1yfs18ajyikm3yyv1mxpbk-a1884 URL: nar/12a910f1k21hayqrwwn8w7ydwvpwwxa1vqp6idhar70b5b2hv3mh.nar.zst1885 Compression: zstd1886 NarHash: sha256:12a910f1k21hayqrwwn8w7ydwvpwwxa1vqp6idhar70b5b2hv3mh1887 NarSize: 2641888 References: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientPushesUseOnePush2759757726/001/store/vd1gw8sngx6rfih83d00xbky3slxxm4g-shared-dep1889 CA: text:sha256:0hfyb83f6jfg86b7r5wjksvhx7sk8vrdir0zyb1nm5c3l7gykv9y1890 client_pushes_test.go:97: Retrieved narinfo from S3:1891 StorePath: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientPushesUseOnePush2759757726/001/store/85yc36d0mnk4x1qf81jc3z1nwq42cwlc-b1892 URL: nar/12a910f1k21hayqrwwn8w7ydwvpwwxa1vqp6idhar70b5b2hv3mh.nar.zst1893 Compression: zstd1894 NarHash: sha256:12a910f1k21hayqrwwn8w7ydwvpwwxa1vqp6idhar70b5b2hv3mh1895 NarSize: 2641896 References: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientPushesUseOnePush2759757726/001/store/vd1gw8sngx6rfih83d00xbky3slxxm4g-shared-dep1897 CA: text:sha256:0hfyb83f6jfg86b7r5wjksvhx7sk8vrdir0zyb1nm5c3l7gykv9y1898=== NAME TestOrphanedObjectsGCStressTest1899 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1900--- PASS: TestClientPushesUseOnePush (10.01s)1901=== NAME TestOrphanedObjectsGCStressTest1902 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1903=== NAME TestClientMultipleUploads1904 client_integration_test.go:358: Created store path 0: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientMultipleUploads843490634/001/store/5v9ifbmjlbavnv3bn33sfvfskqrwi3z3-test-file-0.txt1905 client_integration_test.go:358: Created store path 1: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientMultipleUploads843490634/001/store/qz7gfnc94nwzqdxh8m8sfvsmdz0mwkxr-test-file-1.txt1906 client_integration_test.go:358: Created store path 2: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientMultipleUploads843490634/001/store/7wbklnclvq8b46yp2778q2v84x6hgky9-test-file-2.txt1907=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1908=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1909=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1910=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1911=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1912=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1913=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1914=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1915=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1916=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1917=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1918=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19192026/10/07 06:13:27 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]19202026/10/07 06:13:27 WARN Authentication failed token_preview=eyJhbGciOi...Tdi0iGaSGA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1921--- PASS: TestService_AuthMiddleware_OIDC (8.52s)1922 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1923 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1924 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1925 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)19262026/10/07 06:13:27 INFO Received push request method=POST path=/api/pushes19272026/10/07 06:13:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019282026/10/07 06:13:27 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19292026/10/07 06:13:27 INFO Uploading 5v9ifbmjlbavnv3bn33sfvfskqrwi3z3-test-file-0.txt (160B)19302026/10/07 06:13:27 INFO Uploading 7wbklnclvq8b46yp2778q2v84x6hgky9-test-file-2.txt (160B)19312026/10/07 06:13:27 INFO Uploading qz7gfnc94nwzqdxh8m8sfvsmdz0mwkxr-test-file-1.txt (160B)19322026/10/07 06:13:27 INFO Received create pin request method=POST path=/api/pins/myapp19332026/10/07 06:13:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19342026/10/07 06:13:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19352026/10/07 06:13:27 WARN Failed to register uploaded object key=qz7gfnc94nwzqdxh8m8sfvsmdz0mwkxr.ls error="server returned 404: 404 page not found\n"19362026/10/07 06:13:27 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19372026/10/07 06:13:27 WARN Failed to register uploaded object key=5v9ifbmjlbavnv3bn33sfvfskqrwi3z3.ls error="server returned 404: 404 page not found\n"19382026/10/07 06:13:27 WARN Failed to register uploaded object key=7wbklnclvq8b46yp2778q2v84x6hgky9.ls error="server returned 404: 404 page not found\n"19392026/10/07 06:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19402026/10/07 06:13:27 INFO Created/updated pin name=myapp store_path=/private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestPinProtectsFromGC4234992708/001/store/cd2agqhpyqx5gfxm804573y4syykhxl6-pinned-file.txt narinfo_key=cd2agqhpyqx5gfxm804573y4syykhxl6.narinfo19412026/10/07 06:13:27 INFO Signed narinfos id=1 count=319422026/10/07 06:13:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures19432026/10/07 06:13:27 INFO Uploading 3 narinfos19442026/10/07 06:13:27 INFO Garbage collection started19452026/10/07 06:13:27 INFO Aborted multipart uploads count=0 kept=019462026/10/07 06:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period19472026/10/07 06:13:27 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=019482026/10/07 06:13:27 INFO Vacuumed table table=pending_closures19492026/10/07 06:13:27 WARN Failed to register uploaded object key=5v9ifbmjlbavnv3bn33sfvfskqrwi3z3.narinfo error="server returned 404: 404 page not found\n"19502026/10/07 06:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete19512026/10/07 06:13:27 WARN Failed to register uploaded object key=7wbklnclvq8b46yp2778q2v84x6hgky9.narinfo error="server returned 404: 404 page not found\n"19522026/10/07 06:13:27 WARN Failed to register uploaded object key=qz7gfnc94nwzqdxh8m8sfvsmdz0mwkxr.narinfo error="server returned 404: 404 page not found\n"19532026/10/07 06:13:27 INFO Vacuumed table table=pending_objects19542026/10/07 06:13:27 INFO Vacuumed table table=multipart_uploads19552026/10/07 06:13:27 INFO Vacuumed table table=closures19562026/10/07 06:13:27 INFO Completed push id=1 objects=9 duration=20.364875ms19572026/10/07 06:13:27 INFO Upload complete. (241ms)1958=== NAME TestClientMultipleUploads1959 client_integration_test.go:369: Uploaded 3 paths in 296.737958ms19602026/10/07 06:13:27 INFO Vacuumed table table=objects1961=== NAME TestClientWithDependencies1962 client_integration_test.go:613: Built derivation: /private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientWithDependencies2644336838/001/store/vw269x06f1854gcizxwhb0widfsbr3vm-test-script1963--- PASS: TestClientMultipleUploads (10.35s)1964=== NAME TestClientWithDependencies1965 client_integration_test.go:615: Found 1 dependencies (including self)19662026/10/07 06:13:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19672026/10/07 06:13:27 WARN mTLS auth: bound subjects configured but subject DN unavailable19682026/10/07 06:13:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1969--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (8.55s)19702026/10/07 06:13:27 INFO Received push request method=POST path=/api/pushes19712026/10/07 06:13:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19722026/10/07 06:13:27 INFO Uploading vw269x06f1854gcizxwhb0widfsbr3vm-test-script (136B)19732026/10/07 06:13:27 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19742026/10/07 06:13:27 WARN Failed to register uploaded object key=vw269x06f1854gcizxwhb0widfsbr3vm.ls error="server returned 404: 404 page not found\n"19752026/10/07 06:13:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.532809474s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19762026/10/07 06:13:27 WARN Failed to register uploaded object key=log/j9xxvqngh8qn1nizrkf04grhj9pyxw7m-test-script.drv error="server returned 404: 404 page not found\n"19772026/10/07 06:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19782026/10/07 06:13:27 INFO Signed narinfos id=1 count=119792026/10/07 06:13:27 INFO Uploading 1 narinfos19802026/10/07 06:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete19812026/10/07 06:13:27 WARN Failed to register uploaded object key=vw269x06f1854gcizxwhb0widfsbr3vm.narinfo error="server returned 404: 404 page not found\n"19822026/10/07 06:13:27 INFO Completed push id=1 objects=4 duration=10.066541ms19832026/10/07 06:13:27 INFO Upload complete. (125ms)1984=== NAME TestClientWithDependencies1985 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/lib/tribuchet/a6/scratch/8a9107c325d34ddc/build/TestClientWithDependencies2644336838/001/store) requires matching store prefix1986--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.40s)1987--- PASS: TestClientWithDependencies (10.23s)19882026-10-07 06:13:27.621 UTC [75495] LOG: checkpoint starting: wal1989--- PASS: TestDeleteClosuresRacingPins (12.05s)19902026/10/07 06:13:27 INFO Aborted multipart uploads count=0 kept=019912026/10/07 06:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period1992--- PASS: TestObjectStatsLargeCommit (16.64s)19932026/10/07 06:13:28 INFO Aborted multipart uploads count=0 kept=019942026/10/07 06:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period19952026/10/07 06:13:28 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52402/bucket93/?delete=\": context canceled"1996--- PASS: TestGCEndsOnShutdown (0.01s)1997 --- PASS: TestGCEndsOnShutdown/before_the_run (7.38s)1998 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.00s)1999 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.94s)20002026/10/07 06:13:28 INFO Received uploads request method=POST path=/api/pending_closures20012026/10/07 06:13:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02002=== NAME TestClientIntegration2003 client_integration_test.go:323: Objects in database after GC:2004 client_integration_test.go:323: Successfully deleted all objects with GC --force20052026/10/07 06:13:28 INFO Received uploads request method=POST path=/api/pending_closures2006{"timestamp":"2026-10-07T06:13:28.318854Z","level":"ERROR","duration":"49.654333ms","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(6)"}2007{"timestamp":"2026-10-07T06:13:28.319197Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"42765d56-1b57-4738-b3af-b025df8338da","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket96/","status_code":500,"suppressed_errors":0,"duration_ms":50,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}20082026/10/07 06:13:28 INFO Aborted multipart uploads count=0 kept=02009--- PASS: TestClientIntegration (12.01s)20102026/10/07 06:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period20112026/10/07 06:13:28 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=020122026/10/07 06:13:28 INFO Vacuumed table table=pending_closures20132026/10/07 06:13:28 INFO Vacuumed table table=pending_objects20142026/10/07 06:13:28 INFO Vacuumed table table=multipart_uploads20152026/10/07 06:13:28 INFO Vacuumed table table=closures20162026/10/07 06:13:28 INFO Vacuumed table table=objects2017=== NAME TestOrphanedObjectsGCStressTest2018 orphaned_objects_gc_test.go:503: Stress test completed successfully:2019 orphaned_objects_gc_test.go:504: - Active objects preserved: 202020 orphaned_objects_gc_test.go:505: - Objects deleted: 2102021 orphaned_objects_gc_test.go:506: - Total GC'd: 2102022--- PASS: TestOrphanedObjectsGCStressTest (17.92s)20232026/10/07 06:13:28 INFO Received uploads request method=POST path=/api/pending_closures20242026/10/07 06:13:28 INFO Aborted multipart uploads count=0 kept=020252026/10/07 06:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period20262026/10/07 06:13:28 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=020272026/10/07 06:13:28 INFO Vacuumed table table=pending_closures20282026/10/07 06:13:28 INFO Vacuumed table table=pending_objects20292026/10/07 06:13:28 INFO Vacuumed table table=multipart_uploads20302026/10/07 06:13:28 INFO Vacuumed table table=closures20312026/10/07 06:13:28 INFO Vacuumed table table=objects2032--- PASS: TestForceGCDuringPushOffersSweptObject (0.02s)2033 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.17s)2034 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.35s)2035--- PASS: TestPendingClosureWriteTimeout (0.01s)2036 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2037 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2038 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2039 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.83s)20402026/10/07 06:13:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/07 06:13:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.50805ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/07 06:13:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20432026/10/07 06:13:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2044=== NAME TestPinProtectsFromGC2045 client_integration_test.go:840: Pin successfully protected closure from garbage collection2046--- PASS: TestPinProtectsFromGC (13.65s)20472026/10/07 06:13:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.159409ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2048--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2049 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.60s)2050 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.20s)20512026/10/07 06:13:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.751796ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/07 06:13:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.608728226s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/07 06:13:32 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"20542026/10/07 06:13:32 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/07 06:13:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.087934ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/07 06:13:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.125944ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/07 06:13:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.102195ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/07 06:13:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.741040994s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20592026/10/07 06:13:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20602026/10/07 06:13:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.636294ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20612026/10/07 06:13:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.325552ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20622026/10/07 06:13:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.672573ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20632026/10/07 06:13:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.70023141s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2064--- PASS: TestClientErrorHandling (0.01s)2065 --- PASS: TestClientErrorHandling/InvalidStorePath (4.48s)2066 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.50s)2067 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.15s)2068FAIL2069{"timestamp":"2026-10-07T06:13:38.590326Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52566","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(7)"}20702026-10-07 06:13:38.819 UTC [75475] LOG: received smart shutdown request20712026-10-07 06:13:38.820 UTC [75475] LOG: background worker "logical replication launcher" (PID 75500) exited with exit code 120722026-10-07 06:13:41.058 UTC [75495] LOG: checkpoint complete: wrote 11517 buffers (70.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.121 s, sync=1.254 s, total=13.438 s; sync files=34046, longest=0.002 s, average=0.001 s; distance=533802 kB, estimate=533802 kB; lsn=0/22CADD88, redo lsn=0/220D799820732026-10-07 06:13:41.060 UTC [75495] LOG: shutting down20742026-10-07 06:13:41.061 UTC [75495] LOG: checkpoint starting: shutdown immediate20752026-10-07 06:13:41.086 UTC [75495] LOG: checkpoint complete: wrote 264 buffers (1.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.024 s, sync=0.002 s, total=0.027 s; sync files=70, longest=0.001 s, average=0.001 s; distance=12121 kB, estimate=481634 kB; lsn=0/22CADE00, redo lsn=0/22CADE0020762026-10-07 06:13:41.095 UTC [75475] LOG: database system is shut down