niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #393 · 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 TestShellSplit101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== PAUSE TestEncodeNixBase32/test_string_hash104=== RUN TestEncodeNixBase32/empty_input105=== PAUSE TestEncodeNixBase32/empty_input106--- PASS: TestShellSplit (0.00s)107=== CONT TestPathInfoHashCompatibility108=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)109=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)110=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon111=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon112=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI113=== CONT TestGetStorePathHash114=== RUN TestGetStorePathHash/valid_store_path115=== PAUSE TestGetStorePathHash/valid_store_path116=== RUN TestGetStorePathHash/basename_without_hyphen_should_error117=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error118=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error119=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error120=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error121=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error122=== CONT TestConvertHashToNix32123=== RUN TestConvertHashToNix32/SRI_format_to_Nix32124=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32125=== RUN TestConvertHashToNix32/already_Nix32_format126=== PAUSE TestConvertHashToNix32/already_Nix32_format127=== RUN TestConvertHashToNix32/invalid_format128=== PAUSE TestConvertHashToNix32/invalid_format129=== CONT TestEncodeNixBase32WithRealHash130=== CONT TestDumpPathMatchesNix131=== CONT TestSetClientTLSErrors132=== CONT TestScriptTokenEmptyCommand133=== CONT TestScriptTokenScriptFails134=== CONT TestDumpPathWriterError135=== CONT TestScriptTokenBadJSON136=== CONT TestScriptTokenEmptyToken137=== CONT TestScriptTokenCachesUntilRefresh138=== CONT TestScriptTokenNoExpiryRerunsEveryCall139=== CONT TestFileTokenEmpty140=== CONT TestFileTokenMissing141=== CONT TestFileTokenReadsAndCaches142=== CONT TestStaticToken143=== CONT TestDumpPathSingleFile144=== CONT TestParsePathInfoJSONMultiplePaths145=== CONT TestDoWithRetry_BodyReplayedViaGetBody146=== CONT TestResolveStorePath147=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess148=== CONT TestRateLimiterFeedback149=== CONT TestParsePathInfoJSON150=== CONT TestPathInfoCACompatibility151=== CONT TestUploadMultipart_SupersededByPeer152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== CONT TestStreamPushRequestLine156=== RUN TestRateLimiterFeedback/429_enables_limiter157=== CONT TestClientSignaturesByStorePath158=== PAUSE TestRateLimiterFeedback/429_enables_limiter159=== CONT TestStreamPushReportsSignatures160=== RUN TestSetClientTLSErrors/missing_cert_file161=== CONT TestSetClientTLSDoesNotMutateDefaultTransport162=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== CONT TestSetClientTLS1642026/10/07 06:22:49 ERROR Upload failed error=boom count=1165=== CONT TestStreamPushBatchesUnderLoad166=== RUN TestRateLimiterFeedback/503_enables_limiter167--- PASS: TestEncodeNixBase32WithRealHash (0.00s)168=== PAUSE TestSetClientTLSErrors/missing_cert_file169=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1702026/10/07 06:22:49 ERROR Upload failed error=boom count=1171=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172--- PASS: TestScriptTokenEmptyCommand (0.00s)173=== CONT TestStreamPushReportsEveryPath174=== CONT TestStreamPushGivesUpOnDeadServer175=== RUN TestParsePathInfoJSON/Nix_format176=== RUN TestPathInfoCACompatibility/null_ca_field1772026/10/07 06:22:49 ERROR Upload failed error="connection refused" count=201782026/10/07 06:22:49 ERROR Server seems unavailable, giving up on batch untried=17179=== RUN TestUploadMultipart_SupersededByPeer/exists180=== PAUSE TestRateLimiterFeedback/503_enables_limiter181=== RUN TestSetClientTLSErrors/missing_key_file182--- PASS: TestFileTokenEmpty (0.00s)183--- PASS: TestStaticToken (0.00s)184--- PASS: TestClientSignaturesByStorePath (0.00s)185--- PASS: TestStreamPushReportsSignatures (0.00s)186--- PASS: TestFileTokenMissing (0.00s)187--- PASS: TestScriptTokenScriptFails (0.01s)188--- PASS: TestDoServerRequestAttachesToken (0.01s)189=== PAUSE TestPathInfoCACompatibility/null_ca_field190=== RUN TestPathInfoCACompatibility/old_string_format_-_text191=== CONT TestStreamPushIsolatesFailures1922026/10/07 06:22:49 WARN Rate limiter enabled after throttle name=server-test rate=5193=== CONT TestPartSizeForNAR194=== RUN TestPartSizeForNAR/zero_stays_at_minimum195--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)196--- PASS: TestStreamPushReportsEveryPath (0.00s)197--- PASS: TestFileTokenReadsAndCaches (0.01s)198=== PAUSE TestParsePathInfoJSON/Nix_format199=== CONT TestFilterOversizedClosures200=== RUN TestFilterOversizedClosures/no_limit_keeps_everything201=== RUN TestParsePathInfoJSON/Lix_format2022026/10/07 06:22:49 WARN Rate limiter enabled after throttle name=server-test rate=5203=== PAUSE TestParsePathInfoJSON/Lix_format204=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2052026/10/07 06:22:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54121206--- PASS: TestResolveStorePath (0.01s)207=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything2082026/10/07 06:22:49 ERROR Upload failed error="bad path" count=3209=== CONT TestCaseHackSuffix210--- PASS: TestStreamPushIsolatesFailures (0.00s)211=== CONT TestUploadMultipart_PartsInParallel212=== RUN TestParsePathInfoJSON/empty_input213=== PAUSE TestParsePathInfoJSON/empty_input214=== RUN TestParsePathInfoJSON/whitespace_only215=== PAUSE TestParsePathInfoJSON/whitespace_only216=== RUN TestParsePathInfoJSON/invalid_JSON217=== PAUSE TestParsePathInfoJSON/invalid_JSON218=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped219=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped220=== RUN TestFilterOversizedClosures/all_closures_skipped221=== PAUSE TestFilterOversizedClosures/all_closures_skipped222=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica223=== CONT TestShellSplitErrors224--- PASS: TestShellSplitErrors (0.00s)225=== CONT TestRegisterUploadedObjectReusesConnections226--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)227=== CONT TestEncodeNixBase32/test_string_hash228=== CONT TestEncodeNixBase32/empty_input229--- PASS: TestEncodeNixBase32 (0.00s)230 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)231 --- PASS: TestEncodeNixBase32/empty_input (0.00s)232=== CONT TestGetStorePathHash/valid_store_path233=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error234=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error235=== CONT TestGetStorePathHash/basename_without_hyphen_should_error236--- PASS: TestGetStorePathHash (0.00s)237 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)238 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)239 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)240 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)241=== CONT TestConvertHashToNix32/SRI_format_to_Nix32242=== CONT TestConvertHashToNix32/invalid_format243=== CONT TestConvertHashToNix32/already_Nix32_format244--- PASS: TestConvertHashToNix32 (0.00s)245 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)246 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)247 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)248=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)249=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon250=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI252--- PASS: TestPathInfoHashCompatibility (0.01s)253 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)254 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)255 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)256 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)257=== CONT TestParsePathInfoJSON/Nix_format258--- PASS: TestScriptTokenBadJSON (0.02s)259=== CONT TestFilterOversizedClosures/no_limit_keeps_everything260=== CONT TestParsePathInfoJSON/invalid_JSON261=== CONT TestParsePathInfoJSON/whitespace_only262=== CONT TestParsePathInfoJSON/empty_input263=== CONT TestParsePathInfoJSON/Lix_format264=== CONT TestFilterOversizedClosures/all_closures_skipped265=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2662026/10/07 06:22:49 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=50267=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped268=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2692026/10/07 06:22:49 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=2000270=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths271--- PASS: TestFilterOversizedClosures (0.00s)272 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)273 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)274 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)275--- PASS: TestParsePathInfoJSON (0.01s)276 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)277 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)278 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)279 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)280 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)281=== PAUSE TestUploadMultipart_SupersededByPeer/exists282=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text2832026/10/07 06:22:49 WARN Rate limiter backed off name=server-test rate=52842026/10/07 06:22:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54121285=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter286=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter287=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter288=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter289=== CONT TestRateLimiterFeedback/429_enables_limiter290=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter291=== CONT TestRateLimiterFeedback/503_enables_limiter292=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter293=== RUN TestUploadMultipart_SupersededByPeer/missing294=== PAUSE TestUploadMultipart_SupersededByPeer/missing295=== CONT TestUploadMultipart_SupersededByPeer/exists296=== CONT TestUploadMultipart_SupersededByPeer/missing297=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive299--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)301 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)302=== PAUSE TestSetClientTLSErrors/missing_key_file303=== RUN TestPathInfoCACompatibility/new_structured_format_-_text304--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)305=== RUN TestSetClientTLSErrors/missing_ca_file306=== PAUSE TestSetClientTLSErrors/missing_ca_file307=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum308=== RUN TestSetClientTLSErrors/invalid_ca_file309=== PAUSE TestSetClientTLSErrors/invalid_ca_file310=== CONT TestSetClientTLSErrors/missing_cert_file311=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text312=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method314=== CONT TestPathInfoCACompatibility/null_ca_field315=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive317=== CONT TestSetClientTLSErrors/missing_ca_file318=== RUN TestPartSizeForNAR/small_stays_at_minimum319=== PAUSE TestPartSizeForNAR/small_stays_at_minimum320=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum321=== RUN TestSetClientTLS/rejects_connection_without_client_cert322=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum323=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts324=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts325=== RUN TestPartSizeForNAR/1_TiB326=== PAUSE TestPartSizeForNAR/1_TiB327=== RUN TestPartSizeForNAR/5_TiB_S3_max_object328=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object329=== RUN TestPartSizeForNAR/capped_at_5_GiB330=== PAUSE TestPartSizeForNAR/capped_at_5_GiB331=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert332=== CONT TestSetClientTLSErrors/invalid_ca_file333=== CONT TestSetClientTLSErrors/missing_key_file3342026/10/07 06:22:49 WARN Rate limiter enabled after throttle name=server-test rate=53352026/10/07 06:22:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:54145336=== CONT TestPathInfoCACompatibility/new_structured_format_-_text337=== CONT TestPartSizeForNAR/zero_stays_at_minimum338=== CONT TestPathInfoCACompatibility/old_string_format_-_text339--- PASS: TestPathInfoCACompatibility (0.02s)340 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)341 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)343 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)344 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)345=== CONT TestPartSizeForNAR/1_TiB346=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum347=== CONT TestPartSizeForNAR/small_stays_at_minimum348=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts349=== CONT TestPartSizeForNAR/capped_at_5_GiB350=== CONT TestPartSizeForNAR/5_TiB_S3_max_object351--- PASS: TestPartSizeForNAR (0.01s)352 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)353 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)354 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)3592026/10/07 06:22:49 INFO Garbage collection started3602026/10/07 06:22:49 INFO Garbage collection started361=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA362=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA363=== RUN TestSetClientTLS/preserves_debug_logging_transport364=== PAUSE TestSetClientTLS/preserves_debug_logging_transport365=== CONT TestSetClientTLS/rejects_connection_without_client_cert366=== CONT TestSetClientTLS/preserves_debug_logging_transport367=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3682026/10/07 06:22:49 WARN Rate limiter backed off name=server-test rate=53692026/10/07 06:22:49 WARN Rate limiter enabled after throttle name=server-test rate=53702026/10/07 06:22:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:54142371--- PASS: TestSetClientTLSErrors (0.02s)372 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)375 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)376--- PASS: TestScriptTokenEmptyToken (0.03s)377--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)3782026/10/07 06:22:49 WARN Rate limiter backed off name=server-test rate=5379--- PASS: TestRateLimiterFeedback (0.02s)380 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)381 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)382 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)383 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)384--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)385 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)386 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3872026/10/07 06:22:49 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=03882026/10/07 06:22:50 WARN Garbage collection finished on another replica. Its statistics are not available here389--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)390--- PASS: TestStreamPushRequestLine (0.04s)391--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)3922026/10/07 06:22:50 http: TLS handshake error from 127.0.0.1:54206: read tcp 127.0.0.1:54124->127.0.0.1:54206: use of closed network connection393--- PASS: TestSetClientTLS (0.02s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)397--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)398--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)399--- PASS: TestDumpPathWriterError (0.08s)400--- PASS: TestDumpPathSingleFile (0.08s)401--- PASS: TestCaseHackSuffix (0.09s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.14s)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/7daf46bdce8694ec/build/postgres4229745845/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/7daf46bdce8694ec/build/postgres4229745845/data -l logfile start434435/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/postgres4229745845:5432 - no response4362026-10-07 06:22:51.948 UTC [27661] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:22:51.948 UTC [27661] LOG: listening on Unix socket "/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/postgres4229745845/.s.PGSQL.5432"4382026-10-07 06:22:51.952 UTC [27668] LOG: database system was shut down at 2026-10-07 06:22:51 UTC4392026-10-07 06:22:51.954 UTC [27661] LOG: database system is ready to accept connections440/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/postgres4229745845:5432 - accepting connections441{"timestamp":"2026-10-07T06:22:52.1754Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"577bcc31-2159-409c-ad87-0a064752d0ea","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(10)"}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:22:52 INFO lead: acquired remote=192.0.2.1:12344902026/10/07 06:22:53 INFO lead: released remote=192.0.2.1:12344912026/10/07 06:22:53 INFO lead: acquired remote=192.0.2.1:12344922026/10/07 06:22:54 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.99s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/07 06:22:54 INFO lead: acquired remote=192.0.2.1:12345002026-10-07 06:22:55.854 UTC [27862] FATAL: terminating connection due to administrator command5012026/10/07 06:22:56 INFO lead: acquired remote=192.0.2.1:12345022026/10/07 06:22:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/07 06:22:57 INFO lead: released remote=192.0.2.1:12345042026/10/07 06:22:57 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)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 TestProxyHeadersOnlyTrustedOnSocket6052026/10/07 06:22:57 INFO Starting HTTP server address=proxy.sock6062026/10/07 06:22:57 INFO Starting HTTP server address=127.0.0.1:542376072026/10/07 06:22:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6082026/10/07 06:22:57 INFO Shutdown signal received, draining in-flight requests timeout=10s609--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.19s)610=== RUN TestIsValidCachePath611=== PAUSE TestIsValidCachePath612=== RUN TestReadProxyNarinfo613=== PAUSE TestReadProxyNarinfo614=== RUN TestReadProxyNarinfoAlreadyDecompressed615=== PAUSE TestReadProxyNarinfoAlreadyDecompressed616=== RUN TestReadProxyContentNegotiation617=== PAUSE TestReadProxyContentNegotiation618=== RUN TestReadProxyNarStreaming619=== PAUSE TestReadProxyNarStreaming620=== RUN TestReadProxy404621=== PAUSE TestReadProxy404622=== RUN TestReadProxyInvalidPath623=== PAUSE TestReadProxyInvalidPath624=== RUN TestReadProxyHead625=== PAUSE TestReadProxyHead626=== RUN TestReadProxyOutlastsServerWriteTimeout627=== PAUSE TestReadProxyOutlastsServerWriteTimeout628=== RUN TestReadProxyConditionalGet629=== PAUSE TestReadProxyConditionalGet630=== RUN TestReadProxyRootRedirectsToIndexHTML631=== PAUSE TestReadProxyRootRedirectsToIndexHTML632=== RUN TestReadProxyDisabled633=== PAUSE TestReadProxyDisabled634=== RUN TestReadRedirectNar635=== PAUSE TestReadRedirectNar636=== RUN TestReadRedirectKeepsNarinfoProxied637=== PAUSE TestReadRedirectKeepsNarinfoProxied638=== RUN TestReadProxyRangeRequest639=== PAUSE TestReadProxyRangeRequest640=== RUN TestReadRedirectUsesPublicS3URL641=== PAUSE TestReadRedirectUsesPublicS3URL642=== RUN TestPush_OverlappingRootsStoreOneRowPerKey643=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey644=== RUN TestPush_CompleteCommitsEveryRoot645=== PAUSE TestPush_CompleteCommitsEveryRoot646=== RUN TestPush_RepeatedRootCommitsOnce647=== PAUSE TestPush_RepeatedRootCommitsOnce648=== RUN TestPush_CompleteWaitsForCleanupOfThePush649=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush650=== RUN TestPush_RootsAreLockedInByteOrder651=== PAUSE TestPush_RootsAreLockedInByteOrder652=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit653=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit654=== RUN TestPush_RejectsBadRequests655=== PAUSE TestPush_RejectsBadRequests656=== RUN TestPush_SignsNarinfosOfItsPendingObjects657=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects658=== RUN TestRedundantMultipartUpload659=== PAUSE TestRedundantMultipartUpload660=== RUN TestCompleteMultipartUpload_ErrorButObjectExists661=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists662=== RUN TestCompletedNarNotReofferedAcrossClosures663=== PAUSE TestCompletedNarNotReofferedAcrossClosures664=== RUN TestPresignedUploadRegisteredBeforeCommit665=== PAUSE TestPresignedUploadRegisteredBeforeCommit666=== RUN TestService_Rustfstest667=== PAUSE TestService_Rustfstest668=== RUN TestParseSize669=== PAUSE TestParseSize670=== RUN TestSkippedUploadsHandler671=== PAUSE TestSkippedUploadsHandler672=== RUN TestSystemdListenerNotActivated673--- PASS: TestSystemdListenerNotActivated (0.00s)674=== RUN TestWatchdogBeatsWhenHealthy675--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)676=== RUN TestWatchdogSkipsWhenUnhealthy6772026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/07 06:22:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"687--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)688=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle690=== RUN TestProxyWriteTimeout691=== PAUSE TestProxyWriteTimeout692=== RUN TestPendingClosureWriteTimeout693=== PAUSE TestPendingClosureWriteTimeout694=== RUN TestIsValidUploadKey695=== PAUSE TestIsValidUploadKey696=== RUN TestUploadHandlersRejectInvalidKeys697=== PAUSE TestUploadHandlersRejectInvalidKeys698=== RUN TestUploadHandlersRejectOversizedBody699=== PAUSE TestUploadHandlersRejectOversizedBody700=== RUN TestService_cleanupPendingClosuresHandler701=== PAUSE TestService_cleanupPendingClosuresHandler702=== RUN TestService_createPendingClosureHandler703=== PAUSE TestService_createPendingClosureHandler704=== RUN TestService_verifyS3Integrity705=== PAUSE TestService_verifyS3Integrity706=== RUN TestCompleteMultipartUnregistered707=== PAUSE TestCompleteMultipartUnregistered708=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT709=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT710=== CONT TestReadProxyRootRedirectsToIndexHTML711=== CONT TestGetExistingObjectsLocksRows712=== CONT TestSweepRechecksPendingAfterLocking713=== CONT TestCompletedNarNotReofferedAcrossClosures714=== CONT TestPush_RepeatedRootCommitsOnce715=== CONT TestMetricsCommit716=== CONT TestService_AuthMiddleware717=== CONT TestReadProxyConditionalGet718=== CONT TestReadProxyHead719=== CONT TestReadProxyInvalidPath720=== CONT TestReadProxy404721=== CONT TestReadProxyNarStreaming722=== CONT TestReadProxyContentNegotiation723=== CONT TestReadProxyNarinfoAlreadyDecompressed724=== CONT TestReadProxyNarinfo725=== CONT TestIsValidCachePath726=== RUN TestIsValidCachePath/narinfo727=== CONT TestParseSingleRange728=== PAUSE TestIsValidCachePath/narinfo729=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars730=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars731=== RUN TestIsValidCachePath/nar_zst732=== PAUSE TestIsValidCachePath/nar_zst733=== RUN TestIsValidCachePath/nar_xz734=== PAUSE TestIsValidCachePath/nar_xz735=== RUN TestIsValidCachePath/nar_bz2736=== RUN TestParseSingleRange/none737=== PAUSE TestParseSingleRange/none738=== RUN TestParseSingleRange/unknown_unit739=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT740=== CONT TestPresentRefreshesOnlyStaleClosures741=== CONT TestCompleteMultipartUnregistered742=== CONT TestPresentReportsOnlyClosureRoots743=== CONT TestService_verifyS3Integrity744=== CONT TestReadProxyOutlastsServerWriteTimeout745=== CONT TestPresentNotReportedWhileGCDeletesClosure746=== PAUSE TestIsValidCachePath/nar_bz2747=== RUN TestIsValidCachePath/nar_uncompressed748=== PAUSE TestIsValidCachePath/nar_uncompressed749=== RUN TestIsValidCachePath/ls750=== PAUSE TestIsValidCachePath/ls751=== RUN TestIsValidCachePath/log752=== PAUSE TestIsValidCachePath/log753=== RUN TestIsValidCachePath/realisation754=== PAUSE TestParseSingleRange/unknown_unit755=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale756=== PAUSE TestIsValidCachePath/realisation757=== RUN TestIsValidCachePath/nix-cache-info758=== RUN TestParseSingleRange/multi-range_ignored759=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale760=== PAUSE TestParseSingleRange/multi-range_ignored761=== RUN TestParseSingleRange/malformed_no_dash762=== PAUSE TestParseSingleRange/malformed_no_dash763=== RUN TestParseSingleRange/malformed_both_empty764=== PAUSE TestParseSingleRange/malformed_both_empty765=== RUN TestParseSingleRange/malformed_end_before_start766=== PAUSE TestParseSingleRange/malformed_end_before_start767=== RUN TestParseSingleRange/closed768=== PAUSE TestParseSingleRange/closed769=== RUN TestParseSingleRange/open-ended770=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh771=== PAUSE TestIsValidCachePath/nix-cache-info772=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh773=== RUN TestIsValidCachePath/index.html774=== PAUSE TestIsValidCachePath/index.html775=== CONT TestService_createPendingClosureHandler776=== PAUSE TestParseSingleRange/open-ended777=== RUN TestParseSingleRange/end_clamped_to_size778=== PAUSE TestParseSingleRange/end_clamped_to_size779=== RUN TestParseSingleRange/suffix780=== PAUSE TestParseSingleRange/suffix781=== RUN TestParseSingleRange/suffix_exceeds_size782=== PAUSE TestParseSingleRange/suffix_exceeds_size783=== RUN TestParseSingleRange/single_byte784=== PAUSE TestParseSingleRange/single_byte785=== RUN TestIsValidCachePath/traversal_parent786=== RUN TestParseSingleRange/start_past_EOF787=== PAUSE TestParseSingleRange/start_past_EOF788=== RUN TestParseSingleRange/start_far_past_EOF789=== PAUSE TestParseSingleRange/start_far_past_EOF790=== PAUSE TestIsValidCachePath/traversal_parent791=== RUN TestIsValidCachePath/traversal_in_middle792=== PAUSE TestIsValidCachePath/traversal_in_middle793=== RUN TestIsValidCachePath/invalid_char_e794=== PAUSE TestIsValidCachePath/invalid_char_e795=== RUN TestIsValidCachePath/invalid_char_u796=== PAUSE TestIsValidCachePath/invalid_char_u797=== RUN TestIsValidCachePath/random_path798=== PAUSE TestIsValidCachePath/random_path799=== RUN TestIsValidCachePath/empty800=== PAUSE TestIsValidCachePath/empty801=== RUN TestIsValidCachePath/leading_slash802=== PAUSE TestIsValidCachePath/leading_slash803=== RUN TestIsValidCachePath/wrong_extension804=== PAUSE TestIsValidCachePath/wrong_extension805=== RUN TestIsValidCachePath/short_hash806=== PAUSE TestIsValidCachePath/short_hash807=== CONT TestCreatePin_ReservedPins808=== CONT TestService_cleanupPendingClosuresHandler8092026/10/07 06:22:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54239/oidc810--- PASS: TestReadProxyConditionalGet (0.72s)811=== CONT TestUploadHandlersRejectOversizedBody812=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure813=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure814=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart815=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart816=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts817=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts818=== CONT TestOrphanedObjectsGCStressTest8192026/10/07 06:22:58 INFO Aborted multipart uploads count=0 kept=08202026/10/07 06:22:58 WARN Force mode enabled - objects will be deleted immediately without grace period8212026/10/07 06:22:58 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=08222026/10/07 06:22:58 INFO Vacuumed table table=pending_closures8232026/10/07 06:22:58 INFO Vacuumed table table=pending_objects8242026/10/07 06:22:58 INFO Vacuumed table table=multipart_uploads8252026/10/07 06:22:58 INFO Vacuumed table table=closures8262026/10/07 06:22:58 INFO Vacuumed table table=objects8272026/10/07 06:22:58 INFO Received push request method=POST path=/api/pushes828--- PASS: TestSweepRechecksPendingAfterLocking (1.24s)829=== CONT TestUploadHandlersRejectInvalidKeys830=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info831=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info832=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal833=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal834=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key835=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key836=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key837=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key838=== CONT TestOrphanedObjectsGC8392026/10/07 06:22:59 INFO Received complete push request method=POST path=/api/pushes/1/complete8402026/10/07 06:22:59 INFO Completed push id=1 objects=4 duration=40.710334ms841--- PASS: TestPush_RepeatedRootCommitsOnce (1.39s)842=== CONT TestIsValidUploadKey843=== RUN TestIsValidUploadKey/narinfo844=== PAUSE TestIsValidUploadKey/narinfo845=== RUN TestIsValidUploadKey/nar_zst846=== PAUSE TestIsValidUploadKey/nar_zst847=== RUN TestIsValidUploadKey/nar_xz848=== PAUSE TestIsValidUploadKey/nar_xz849=== RUN TestIsValidUploadKey/nar_plain850=== PAUSE TestIsValidUploadKey/nar_plain851=== RUN TestIsValidUploadKey/listing852=== PAUSE TestIsValidUploadKey/listing853=== RUN TestIsValidUploadKey/build_log854=== PAUSE TestIsValidUploadKey/build_log855=== RUN TestIsValidUploadKey/build_log_home-manager_file856=== PAUSE TestIsValidUploadKey/build_log_home-manager_file857=== RUN TestIsValidUploadKey/build_log_plus_in_name858=== PAUSE TestIsValidUploadKey/build_log_plus_in_name859=== RUN TestIsValidUploadKey/build_log_question_mark860=== PAUSE TestIsValidUploadKey/build_log_question_mark861=== RUN TestIsValidUploadKey/build_log_equals862=== PAUSE TestIsValidUploadKey/build_log_equals863=== RUN TestIsValidUploadKey/realisation864=== PAUSE TestIsValidUploadKey/realisation865=== RUN TestIsValidUploadKey/realisation_plus_in_output866=== PAUSE TestIsValidUploadKey/realisation_plus_in_output867=== RUN TestIsValidUploadKey/nix-cache-info868=== PAUSE TestIsValidUploadKey/nix-cache-info869=== RUN TestIsValidUploadKey/index.html870=== PAUSE TestIsValidUploadKey/index.html871=== RUN TestIsValidUploadKey/narinfo_key,_nar_type872=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type873=== RUN TestIsValidUploadKey/nar_key,_narinfo_type874=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type875=== RUN TestIsValidUploadKey/listing_key,_narinfo_type876=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type877=== RUN TestIsValidUploadKey/traversal878=== PAUSE TestIsValidUploadKey/traversal879=== RUN TestIsValidUploadKey/traversal_nar880=== PAUSE TestIsValidUploadKey/traversal_nar881=== RUN TestIsValidUploadKey/absolute882=== PAUSE TestIsValidUploadKey/absolute883=== RUN TestIsValidUploadKey/empty_key884=== PAUSE TestIsValidUploadKey/empty_key885=== RUN TestIsValidUploadKey/unknown_type886=== PAUSE TestIsValidUploadKey/unknown_type887=== CONT TestPendingClosureWriteTimeout888=== RUN TestPendingClosureWriteTimeout/empty889=== PAUSE TestPendingClosureWriteTimeout/empty890=== RUN TestPendingClosureWriteTimeout/400_objects891=== PAUSE TestPendingClosureWriteTimeout/400_objects892=== RUN TestPendingClosureWriteTimeout/670k_objects893=== PAUSE TestPendingClosureWriteTimeout/670k_objects894=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline895=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline896=== CONT TestObjectStatsLargeCommit897--- PASS: TestReadProxyNarStreaming (1.54s)898=== CONT TestProxyWriteTimeout899=== RUN TestProxyWriteTimeout/narinfo900=== PAUSE TestProxyWriteTimeout/narinfo901=== RUN TestProxyWriteTimeout/1_GiB_nar902=== PAUSE TestProxyWriteTimeout/1_GiB_nar903=== RUN TestProxyWriteTimeout/10_GiB_nar904=== PAUSE TestProxyWriteTimeout/10_GiB_nar905=== RUN TestProxyWriteTimeout/unknown_size906=== PAUSE TestProxyWriteTimeout/unknown_size907=== CONT TestObjectStatsTrigger908--- PASS: TestReadProxyInvalidPath (2.02s)909=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle910--- PASS: TestGetExistingObjectsLocksRows (2.29s)911=== CONT TestPendingCleanupUsesOneCutoff9122026/10/07 06:23:00 INFO Received uploads request method=POST path=/api/pending_closures9132026/10/07 06:23:00 INFO Received push request method=POST path=/api/pushes9142026/10/07 06:23:00 INFO Received complete push request method=POST path=/api/pushes/1/complete9152026/10/07 06:23:00 INFO Completed push id=1 objects=4 duration=21.198416ms9162026/10/07 06:23:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9172026/10/07 06:23:00 INFO Completed upload id=2 objects=2 duration=898.125µs918--- PASS: TestMetricsCommit (2.81s)919=== CONT TestSkippedUploadsHandler9202026/10/07 06:23:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000921--- PASS: TestSkippedUploadsHandler (0.00s)922=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded923--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.94s)924=== CONT TestParseSize925--- PASS: TestParseSize (0.00s)926=== CONT TestMultipartCleanup927--- PASS: TestReadProxyContentNegotiation (3.27s)928=== CONT TestService_Rustfstest929--- PASS: TestReadProxy404 (3.52s)930=== CONT TestServerTLSConfig931=== RUN TestServerTLSConfig/no_client_CA932=== PAUSE TestServerTLSConfig/no_client_CA933=== RUN TestServerTLSConfig/missing_CA_file934=== PAUSE TestServerTLSConfig/missing_CA_file935=== RUN TestServerTLSConfig/not_a_PEM_file936=== PAUSE TestServerTLSConfig/not_a_PEM_file937=== CONT TestPresignedUploadRegisteredBeforeCommit9382026/10/07 06:23:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"939--- PASS: TestService_AuthMiddleware (3.70s)940=== CONT TestService_NativeMTLS9412026/10/07 06:23:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9422026/10/07 06:23:01 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>943--- PASS: TestReadProxyNarinfo (4.03s)944=== CONT TestPush_RejectsBadRequests9452026/10/07 06:23:01 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLjhjMmY4NTI2LTA4NTktNGM4YS04ZmE3LWJkY2I4ZjgyOWY4MXgxNzkxMzU0MTgwMTc1MjM5MDAw parts=129462026/10/07 06:23:01 INFO Received uploads request method=POST path=/api/pending_closures947--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.05s)948=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9492026/10/07 06:23:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9502026/10/07 06:23:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst951--- PASS: TestCompleteMultipartUnregistered (4.20s)952=== CONT TestRedundantMultipartUpload9532026/10/07 06:23:02 INFO Received uploads request method=POST path=/api/pending_closures954--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.48s)955=== CONT TestPush_SignsNarinfosOfItsPendingObjects956--- PASS: TestPresentRefreshesOnlyStaleClosures (4.63s)957=== CONT TestGCTaskStore_DeduplicateSameParams958--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)959=== CONT TestGCTaskStore_PhaseUpdates960--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)961=== CONT TestGCTaskStore_CompletedAllowsNewTask962--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)963=== CONT TestGCTaskStore_GetReturnsLatest964--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)965=== CONT TestGCTaskStore_GetEmpty966--- PASS: TestGCTaskStore_GetEmpty (0.00s)967=== CONT TestGCTaskStore_ConflictDifferentParams968--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)969=== CONT TestMetricsInventory970--- PASS: TestPresentReportsOnlyClosureRoots (4.84s)971=== CONT TestGenerateLandingPage972--- PASS: TestGenerateLandingPage (0.00s)973=== CONT TestService_readinessHandler974--- PASS: TestReadProxyNarinfoAlreadyDecompressed (5.01s)975=== CONT TestNARDeduplicationMetadataUploadBug9762026/10/07 06:23:03 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/07 06:23:03 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/07 06:23:03 INFO Received uploads request method=POST path=/api/pending_closures979--- PASS: TestReadProxyHead (5.74s)980=== CONT TestCreatePendingClosureRejectsOversizedNAR9812026/10/07 06:23:03 INFO Received uploads request method=POST path=/api/pending_closures982--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)983=== CONT TestCacheConfigHandlerMaxNarSize984--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)985=== CONT TestService_healthCheckHandler9862026/10/07 06:23:03 INFO Received cleanup request method=DELETE path=/api/pending_closures9872026/10/07 06:23:03 INFO Aborted multipart uploads count=0 kept=09882026/10/07 06:23:03 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/07 06:23:03 INFO Received cleanup request method=DELETE path=/api/pending_closures9902026/10/07 06:23:03 INFO Aborted multipart uploads count=1 kept=09912026/10/07 06:23:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9922026-10-07 06:23:03.761 UTC [28687] ERROR: Closure does not exist: id=19932026-10-07 06:23:03.761 UTC [28687] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9942026-10-07 06:23:03.761 UTC [28687] STATEMENT: -- name: CommitPendingClosure :one995 SELECT commit_pending_closure($1::bigint)::bigint996 997--- PASS: TestService_cleanupPendingClosuresHandler (6.08s)998=== CONT TestPush_RootsAreLockedInByteOrder9992026/10/07 06:23:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10002026/10/07 06:23:03 WARN Refused reserved pin name=worker-x86_64-linux10012026/10/07 06:23:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10022026/10/07 06:23:03 INFO Received create pin request method=POST path=/api/pins/my-app10032026/10/07 06:23:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1004--- PASS: TestCreatePin_ReservedPins (6.27s)1005=== CONT TestGracefulShutdownDrainsInflight10062026/10/07 06:23:03 INFO Starting HTTP server address=127.0.0.1:5432710072026/10/07 06:23:03 INFO Shutdown signal received, draining in-flight requests timeout=10s1008--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1009=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit10102026/10/07 06:23:04 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/07 06:23:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10122026/10/07 06:23:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLmJhM2ViMmMxLTdiODgtNGU5YS04YWUzLTAwOTI3ZTMyYjc2N3gxNzkxMzU0MTgzMTkyMTY1MDAw parts=1010132026/10/07 06:23:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10142026/10/07 06:23:04 INFO Completed upload id=1 objects=2 duration=15.771ms10152026/10/07 06:23:04 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010162026/10/07 06:23:04 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/07 06:23:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures10182026/10/07 06:23:04 INFO Aborted multipart uploads count=0 kept=010192026/10/07 06:23:04 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=010202026/10/07 06:23:04 INFO Vacuumed table table=pending_closures10212026/10/07 06:23:04 INFO Vacuumed table table=pending_objects10222026/10/07 06:23:04 INFO Vacuumed table table=multipart_uploads10232026/10/07 06:23:04 INFO Vacuumed table table=closures10242026/10/07 06:23:04 INFO Vacuumed table table=objects10252026/10/07 06:23:04 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001026--- PASS: TestService_createPendingClosureHandler (7.12s)1027=== CONT TestGCTaskStore_Fail1028--- PASS: TestGCTaskStore_Fail (0.00s)1029=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1030--- PASS: TestObjectStatsTrigger (6.13s)1031=== CONT TestRegisterCompletedObjectNeedsPendingRow10322026/10/07 06:23:05 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/07 06:23:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10342026/10/07 06:23:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLmI4MjMxYTQyLTQzZTgtNDZkYS04NWZmLTYxZDJjOWY5MzQ3NHgxNzkxMzU0MTg0MjAwNjYwMDAw parts=1010352026/10/07 06:23:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10362026/10/07 06:23:05 INFO Completed upload id=1 objects=2 duration=15.616333ms10372026/10/07 06:23:05 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/07 06:23:05 INFO Received uploads request method=POST path=/api/pending_closures10392026/10/07 06:23:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10402026/10/07 06:23:05 WARN Found objects in DB but missing from S3, will re-upload count=11041--- PASS: TestService_verifyS3Integrity (8.03s)1042=== CONT TestSweepSkipsRowsLockedByPush1043=== NAME TestOrphanedObjectsGC1044 orphaned_objects_gc_test.go:287: GC Test Summary:1045 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1046 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1047 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1048 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1049 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1050--- PASS: TestOrphanedObjectsGC (6.85s)1051=== CONT TestFailedS3DeleteKeepsTombstone10522026/10/07 06:23:05 INFO Received uploads request method=POST path=/api/pending_closures10532026/10/07 06:23:05 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/07 06:23:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/10/07 06:23:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10562026/10/07 06:23:06 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/07 06:23:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10582026/10/07 06:23:06 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket34/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10592026/10/07 06:23:06 INFO Aborted multipart uploads count=0 kept=110602026/10/07 06:23:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10612026/10/07 06:23:06 INFO Aborted multipart uploads count=1 kept=01062--- PASS: TestMultipartCleanup (5.81s)1063=== CONT TestForceGCDuringPushOffersSweptObject1064=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1065=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1066=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1067=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1068=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10692026/10/07 06:23:06 INFO Received uploads request method=POST path=/api/pending_closures1070--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.14s)1071=== CONT TestGCSweepDeliversEachKeyOnce1072--- PASS: TestService_Rustfstest (5.85s)1073=== CONT TestTombstonedObjectOfferedWithoutWaiting10742026/10/07 06:23:07 INFO Received uploads request method=POST path=/api/pending_closures1075--- PASS: TestReadProxyOutlastsServerWriteTimeout (9.45s)1076=== CONT TestGCSweepSkipsPendingObjects10772026/10/07 06:23:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10782026/10/07 06:23:07 INFO Received uploads request method=POST path=/api/pending_closures1079--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.99s)1080=== CONT TestDeduplicatedObjectsRecordedAsPending10812026/10/07 06:23:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10822026/10/07 06:23:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1083--- PASS: TestService_NativeMTLS (6.01s)1084=== CONT TestPushDedupSurvivesConcurrentGC10852026/10/07 06:23:07 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/07 06:23:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10872026/10/07 06:23:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLmMyYTAzMzk4LTU1MTktNDg5ZS1iNzQ1LTQ1MDM1YjJkNjFlY3gxNzkxMzU0MTg3NzcxMzMyMDAw1088=== RUN TestPush_RejectsBadRequests/no_roots1089=== PAUSE TestPush_RejectsBadRequests/no_roots1090=== RUN TestPush_RejectsBadRequests/no_objects1091=== PAUSE TestPush_RejectsBadRequests/no_objects1092=== RUN TestPush_RejectsBadRequests/bad_root1093=== PAUSE TestPush_RejectsBadRequests/bad_root1094=== RUN TestPush_RejectsBadRequests/root_not_in_objects1095=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1096=== CONT TestClientErrorHandling1097=== RUN TestClientErrorHandling/InvalidStorePath1098=== PAUSE TestClientErrorHandling/InvalidStorePath1099=== RUN TestClientErrorHandling/InvalidAuthToken1100=== PAUSE TestClientErrorHandling/InvalidAuthToken1101=== RUN TestClientErrorHandling/ServerNotAvailable1102=== PAUSE TestClientErrorHandling/ServerNotAvailable1103=== CONT TestGCMetrics11042026/10/07 06:23:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLmMyYTAzMzk4LTU1MTktNDg5ZS1iNzQ1LTQ1MDM1YjJkNjFlY3gxNzkxMzU0MTg3NzcxMzMyMDAw parts=11105--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.39s)1106=== CONT TestDeleteClosuresRacingPins11072026/10/07 06:23:08 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/07 06:23:08 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/07 06:23:08 INFO Received push request method=POST path=/api/pushes11102026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11112026/10/07 06:23:08 INFO Signed narinfos id=1 count=111122026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11132026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11142026/10/07 06:23:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11152026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11162026/10/07 06:23:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11172026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11182026/10/07 06:23:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111192026/10/07 06:23:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11202026/10/07 06:23:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1121--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (6.71s)1122=== CONT TestGCBugBareHashReferences1123--- PASS: TestMetricsInventory (6.81s)1124=== CONT TestGCAdvisoryLockBlocksConcurrentRun11252026/10/07 06:23:09 WARN readiness check failed error="closed pool"1126--- PASS: TestService_readinessHandler (6.81s)1127=== CONT TestClientFallsBackToClosures11282026/10/07 06:23:09 WARN Rate limiter enabled after throttle name=s3-test rate=511292026/10/07 06:23:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1130=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1131 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101132 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001133--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.18s)1134=== CONT TestClientPushesUseOnePush1135=== NAME TestNARDeduplicationMetadataUploadBug1136 metadata_upload_test.go:48: First store path: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestNARDeduplicationMetadataUploadBug1263178663/001/store/8y0qjyc91fpmxzfxlalaaphdkyj6wwsf-file1.txt1137--- PASS: TestService_healthCheckHandler (6.59s)1138=== CONT TestPinProtectsFromGC11392026/10/07 06:23:10 INFO Received push request method=POST path=/api/pushes11402026/10/07 06:23:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11412026/10/07 06:23:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11422026/10/07 06:23:10 INFO Uploading 8y0qjyc91fpmxzfxlalaaphdkyj6wwsf-file1.txt (160B)11432026/10/07 06:23:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11442026/10/07 06:23:10 WARN Failed to register uploaded object key=8y0qjyc91fpmxzfxlalaaphdkyj6wwsf.ls error="server returned 404: 404 page not found\n"11452026/10/07 06:23:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11462026/10/07 06:23:10 INFO Signed narinfos id=1 count=111472026/10/07 06:23:10 INFO Uploading 1 narinfos11482026/10/07 06:23:10 INFO Received complete push request method=POST path=/api/pushes/1/complete11492026/10/07 06:23:10 WARN Failed to register uploaded object key=8y0qjyc91fpmxzfxlalaaphdkyj6wwsf.narinfo error="server returned 404: 404 page not found\n"11502026/10/07 06:23:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLjZjN2RlYTcwLTE3ODctNDRjNS05Y2VhLTA0YjYyZjg3YjFkYngxNzkxMzU0MTg4NDQyMTA4MDAw parts=1211512026/10/07 06:23:10 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/07 06:23:10 INFO Completed push id=1 objects=3 duration=33.124ms11532026/10/07 06:23:10 INFO Upload complete. (291ms)11542026/10/07 06:23:10 INFO Received push request method=POST path=/api/pushes1155=== NAME TestNARDeduplicationMetadataUploadBug1156 metadata_upload_test.go:54: Retrieved narinfo from S3:1157 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestNARDeduplicationMetadataUploadBug1263178663/001/store/8y0qjyc91fpmxzfxlalaaphdkyj6wwsf-file1.txt1158 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1159 Compression: zstd1160 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1161 NarSize: 1601162 References: 1163 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1164 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1165 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1166 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11672026/10/07 06:23:10 INFO Received uploads request method=POST path=/api/pending_closures1168 metadata_upload_test.go:64: Second store path (same content): /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestNARDeduplicationMetadataUploadBug1263178663/001/store/v2b2jag4bl3204igq66pz79in3aks861-file2.txt11692026-10-07 06:23:10.560 UTC [29005] ERROR: could not obtain lock on row in relation "closures"11702026-10-07 06:23:10.560 UTC [29005] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11712026-10-07 06:23:10.564 UTC [29005] ERROR: could not obtain lock on row in relation "closures"11722026-10-07 06:23:10.564 UTC [29005] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11732026-10-07 06:23:10.571 UTC [29005] ERROR: could not obtain lock on row in relation "closures"11742026-10-07 06:23:10.571 UTC [29005] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11752026-10-07 06:23:10.576 UTC [29005] ERROR: could not obtain lock on row in relation "closures"11762026-10-07 06:23:10.576 UTC [29005] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11772026-10-07 06:23:10.582 UTC [29005] ERROR: could not obtain lock on row in relation "closures"11782026-10-07 06:23:10.582 UTC [29005] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1179--- PASS: TestPush_RootsAreLockedInByteOrder (6.84s)1180=== CONT TestLeadEndsOnShutdown11812026/10/07 06:23:10 INFO Received push request method=POST path=/api/pushes11822026/10/07 06:23:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11832026/10/07 06:23:10 INFO Received push request method=POST path=/api/pushes11842026/10/07 06:23:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11852026/10/07 06:23:10 WARN Failed to register uploaded object key=v2b2jag4bl3204igq66pz79in3aks861.ls error="server returned 404: 404 page not found\n"11862026/10/07 06:23:10 INFO Signed narinfos id=2 count=111872026/10/07 06:23:10 INFO Uploading 1 narinfos11882026/10/07 06:23:10 INFO Received complete push request method=POST path=/api/pushes/2/complete11892026/10/07 06:23:10 WARN Failed to register uploaded object key=v2b2jag4bl3204igq66pz79in3aks861.narinfo error="server returned 404: 404 page not found\n"11902026/10/07 06:23:10 INFO Completed push id=2 objects=3 duration=936.5µs11912026/10/07 06:23:10 INFO Upload complete. (179ms)1192=== NAME TestNARDeduplicationMetadataUploadBug1193 metadata_upload_test.go:76: Retrieved narinfo from S3:1194 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestNARDeduplicationMetadataUploadBug1263178663/001/store/v2b2jag4bl3204igq66pz79in3aks861-file2.txt1195 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1196 Compression: zstd1197 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1198 NarSize: 1601199 References: 1200 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1201 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1202 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1203 {"version":1,"root":{"type":"regular","size":44}}12042026/10/07 06:23:10 INFO Received complete push request method=POST path=/api/pushes/1/complete12052026/10/07 06:23:10 INFO Completed push id=1 objects=4 duration=42.914583ms12062026/10/07 06:23:10 INFO Received push request method=POST path=/api/pushes1207=== CONT TestClientSharedPathCommittedMidPush1208--- PASS: TestNARDeduplicationMetadataUploadBug (8.19s)12092026/10/07 06:23:10 INFO Aborted multipart uploads count=0 kept=012102026/10/07 06:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period12112026/10/07 06:23:10 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=012122026/10/07 06:23:11 INFO Vacuumed table table=pending_closures12132026/10/07 06:23:11 INFO Vacuumed table table=pending_objects12142026/10/07 06:23:11 INFO Vacuumed table table=multipart_uploads12152026/10/07 06:23:11 INFO Vacuumed table table=closures12162026/10/07 06:23:11 INFO Vacuumed table table=objects12172026/10/07 06:23:11 INFO Received complete push request method=POST path=/api/pushes/2/complete12182026/10/07 06:23:11 INFO Completed push id=2 objects=4 duration=7.956459ms1219--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.14s)1220=== CONT TestClientWithDependencies1221--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.96s)1222=== CONT TestLeadIncumbentAnnouncesAtOnce1223=== NAME TestOrphanedObjectsGCStressTest1224 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1225 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion12262026/10/07 06:23:11 INFO Aborted multipart uploads count=0 kept=012272026/10/07 06:23:11 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/07 06:23: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=012292026/10/07 06:23:11 INFO Vacuumed table table=pending_closures12302026/10/07 06:23:11 INFO Vacuumed table table=pending_objects12312026/10/07 06:23:11 INFO Vacuumed table table=multipart_uploads12322026/10/07 06:23:11 INFO Vacuumed table table=closures12332026/10/07 06:23:11 INFO Vacuumed table table=objects12342026/10/07 06:23:11 INFO Aborted multipart uploads count=0 kept=012352026/10/07 06:23:11 WARN Force mode enabled - objects will be deleted immediately without grace period12362026/10/07 06:23: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=012372026/10/07 06:23:11 INFO Vacuumed table table=pending_closures12382026/10/07 06:23:11 INFO Vacuumed table table=pending_objects12392026/10/07 06:23:11 INFO Vacuumed table table=multipart_uploads12402026/10/07 06:23:11 INFO Vacuumed table table=closures12412026/10/07 06:23:11 INFO Vacuumed table table=objects1242--- PASS: TestSweepSkipsRowsLockedByPush (6.11s)1243=== CONT TestClientMultipleUploads12442026/10/07 06:23:11 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/07 06:23:12 INFO Aborted multipart uploads count=1 kept=012462026/10/07 06:23:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12472026/10/07 06:23:12 INFO Aborted multipart uploads count=1 kept=01248--- PASS: TestPendingCleanupUsesOneCutoff (12.15s)1249=== CONT TestClientIntegration12502026/10/07 06:23:12 INFO Aborted multipart uploads count=0 kept=012512026/10/07 06:23:12 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/07 06:23:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12532026/10/07 06:23:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12542026/10/07 06:23:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1255--- PASS: TestFailedS3DeleteKeepsTombstone (6.39s)1256=== CONT TestLeadElectsOneAndHandsOver12572026/10/07 06:23:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLmJmNDlmY2NiLWY4ZTQtNGEyMi1iY2Q0LTJmODZkNDljOTk5ZHgxNzkxMzU0MTkwNDI2OTM4MDAw error="Get \"http://127.0.0.1:1/bucket41/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12582026/10/07 06:23:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGJkM2NmNzYtOGIyYy00ZjE5LWExMmUtYTg1YTc1ZGIwZDczLjBmMWExNTk3LWQxNzQtNDFjZS1hNDFmLTkwYmI4ZGMxYzlhZngxNzkxMzU0MTkwMzUxODAxMDAw parts=1212592026/10/07 06:23:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12602026/10/07 06:23:12 INFO Aborted multipart uploads count=1 kept=01261--- PASS: TestRedundantMultipartUpload (10.40s)1262=== CONT TestConnectWaitsForAPeerMigration12632026/10/07 06:23:12 INFO Received uploads request method=POST path=/api/pending_closures1264--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.56s)1265=== CONT TestService_RequireScope_OIDC12662026/10/07 06:23:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54437/oidc1267--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.09s)1268=== CONT TestResolveDBConnectionString1269=== RUN TestResolveDBConnectionString/flag_wins1270=== PAUSE TestResolveDBConnectionString/flag_wins1271=== RUN TestResolveDBConnectionString/file_when_flag_empty1272=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1273=== RUN TestResolveDBConnectionString/missing_file_is_an_error1274=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1275=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1276=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1277=== RUN TestResolveDBConnectionString/nothing_configured1278=== PAUSE TestResolveDBConnectionString/nothing_configured1279=== CONT TestClientCADerivations12802026/10/07 06:23:12 INFO Aborted multipart uploads count=0 kept=012812026/10/07 06:23:12 WARN Force mode enabled - objects will be deleted immediately without grace period12822026/10/07 06:23: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=012832026/10/07 06:23:12 INFO Vacuumed table table=pending_closures12842026/10/07 06:23:12 INFO Vacuumed table table=pending_objects12852026/10/07 06:23:12 INFO Vacuumed table table=multipart_uploads12862026/10/07 06:23:12 INFO Vacuumed table table=closures12872026/10/07 06:23:12 INFO Vacuumed table table=objects1288--- PASS: TestGCSweepDeliversEachKeyOnce (6.13s)1289=== CONT TestReadProxyRangeRequest12902026/10/07 06:23:12 INFO Received uploads request method=POST path=/api/pending_closures1291--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.03s)1292=== CONT TestCacheStatsHandler12932026/10/07 06:23:13 INFO Received uploads request method=POST path=/api/pending_closures1294--- PASS: TestDeduplicatedObjectsRecordedAsPending (5.88s)1295=== CONT TestPush_CompleteCommitsEveryRoot12962026/10/07 06:23:13 INFO Received uploads request method=POST path=/api/pending_closures12972026/10/07 06:23:13 INFO Aborted multipart uploads count=0 kept=012982026/10/07 06:23:13 WARN Force mode enabled - objects will be deleted immediately without grace period12992026/10/07 06:23: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=013002026/10/07 06:23:13 INFO Vacuumed table table=pending_closures13012026/10/07 06:23:13 INFO Vacuumed table table=pending_objects13022026/10/07 06:23:13 INFO Vacuumed table table=multipart_uploads13032026/10/07 06:23:13 INFO Vacuumed table table=closures13042026/10/07 06:23:13 INFO Vacuumed table table=objects1305--- PASS: TestGCSweepSkipsPendingObjects (6.30s)1306=== CONT TestCacheConfigHandler1307=== RUN TestCacheConfigHandler/full_config,_no_issuer1308=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1309=== RUN TestCacheConfigHandler/no_cache_url_configured1310=== PAUSE TestCacheConfigHandler/no_cache_url_configured1311=== RUN TestCacheConfigHandler/no_signing_keys1312=== PAUSE TestCacheConfigHandler/no_signing_keys1313=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1314=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1315=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13162026/10/07 06:23:13 INFO Received uploads request method=POST path=/api/pending_closures13172026/10/07 06:23:13 INFO Aborted multipart uploads count=0 kept=013182026/10/07 06:23: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=013192026/10/07 06:23:13 INFO Vacuumed table table=pending_closures13202026/10/07 06:23:13 INFO Vacuumed table table=pending_objects13212026/10/07 06:23:13 INFO Vacuumed table table=multipart_uploads13222026/10/07 06:23:13 INFO Vacuumed table table=closures13232026/10/07 06:23:13 INFO Vacuumed table table=objects13242026/10/07 06:23:13 INFO Aborted multipart uploads count=0 kept=013252026/10/07 06:23:13 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/07 06:23:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013272026/10/07 06:23:14 INFO Vacuumed table table=pending_closures13282026/10/07 06:23:14 INFO Vacuumed table table=pending_objects13292026/10/07 06:23:14 INFO Vacuumed table table=multipart_uploads13302026/10/07 06:23:14 INFO Vacuumed table table=closures13312026/10/07 06:23:14 INFO Vacuumed table table=objects1332--- PASS: TestPushDedupSurvivesConcurrentGC (6.67s)1333=== CONT TestService_ReadScope_PublicByDefault13342026/10/07 06:23:14 INFO Aborted multipart uploads count=0 kept=013352026/10/07 06:23:14 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/07 06:23:14 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=013372026/10/07 06:23:14 INFO Vacuumed table table=pending_closures13382026/10/07 06:23:14 INFO Vacuumed table table=pending_objects13392026/10/07 06:23:14 INFO Vacuumed table table=multipart_uploads13402026/10/07 06:23:14 INFO Vacuumed table table=closures13412026/10/07 06:23:14 INFO Vacuumed table table=objects1342--- PASS: TestGCMetrics (6.25s)1343=== CONT TestReadRedirectUsesPublicS3URL1344{"timestamp":"2026-10-07T06:23:14.444569Z","level":"ERROR","message":"data usage snapshot load failed","event":"data_usage_snapshot_load_failed","component":"ecstore","subsystem":"data_usage","state":"read_failed","operation":"remove_bucket_from_observed","reason":"io","object":"buckets/.usage.observed.json","error":"Io error: Too many open files (os error 24)","target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage/mod.rs","line_number":968,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}1345=== NAME TestOrphanedObjectsGCStressTest1346 orphaned_objects_gc_test.go:503: Stress test completed successfully:1347 orphaned_objects_gc_test.go:504: - Active objects preserved: 201348 orphaned_objects_gc_test.go:505: - Objects deleted: 2101349 orphaned_objects_gc_test.go:506: - Total GC'd: 2101350--- PASS: TestOrphanedObjectsGCStressTest (16.15s)1351=== CONT TestPush_CompleteWaitsForCleanupOfThePush1352--- PASS: TestGCBugBareHashReferences (5.98s)1353=== CONT TestReadRedirectNar1354--- PASS: TestObjectStatsLargeCommit (15.78s)1355=== CONT TestReadProxyDisabled13562026/10/07 06:23: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"1357--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.77s)1358=== CONT TestReadRedirectKeepsNarinfoProxied13592026/10/07 06:23:15 INFO Received push request method=POST path=/api/pushes13602026/10/07 06:23:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13612026/10/07 06:23:15 INFO Uploading 81fb599qnxmadwqxdx6dhjkakcwhqqmx-shared-dep (136B)13622026/10/07 06:23:15 INFO Uploading y96wf0cb3mvljfyk02pxpc9w32ipw54y-a (264B)13632026/10/07 06:23:15 WARN Failed to register uploaded object key=81fb599qnxmadwqxdx6dhjkakcwhqqmx.ls error="server returned 404: 404 page not found\n"13642026/10/07 06:23:15 WARN Failed to register uploaded object key=nar/1yz34sv97gchidalrisf2j7vsjv0rzfxhygs4qgizl42p3gx6q43.nar.zst error="server returned 404: 404 page not found\n"13652026/10/07 06:23:15 WARN Failed to register uploaded object key=y96wf0cb3mvljfyk02pxpc9w32ipw54y.ls error="server returned 404: 404 page not found\n"13662026/10/07 06:23:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13672026/10/07 06:23:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13682026/10/07 06:23:15 WARN Failed to register uploaded object key=7phv74v0mljlnvkqhckqixj2v4d2hpf2.ls error="server returned 404: 404 page not found\n"13692026/10/07 06:23:15 INFO Signed narinfos id=1 count=313702026/10/07 06:23:15 INFO Uploading 3 narinfos13712026/10/07 06:23:15 WARN Failed to register uploaded object key=7phv74v0mljlnvkqhckqixj2v4d2hpf2.narinfo error="server returned 404: 404 page not found\n"13722026/10/07 06:23:15 WARN Failed to register uploaded object key=81fb599qnxmadwqxdx6dhjkakcwhqqmx.narinfo error="server returned 404: 404 page not found\n"13732026/10/07 06:23:15 INFO Received complete push request method=POST path=/api/pushes/1/complete13742026/10/07 06:23:15 WARN Failed to register uploaded object key=y96wf0cb3mvljfyk02pxpc9w32ipw54y.narinfo error="server returned 404: 404 page not found\n"13752026/10/07 06:23:15 INFO Completed push id=1 objects=8 duration=19.118458ms13762026/10/07 06:23:15 INFO Upload complete. (284ms)1377=== NAME TestClientPushesUseOnePush1378 client_pushes_test.go:97: Retrieved narinfo from S3:1379 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientPushesUseOnePush3281767447/001/store/81fb599qnxmadwqxdx6dhjkakcwhqqmx-shared-dep1380 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1381 Compression: zstd1382 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821383 NarSize: 1361384 References: 1385 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1386 client_pushes_test.go:97: Retrieved narinfo from S3:1387 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientPushesUseOnePush3281767447/001/store/y96wf0cb3mvljfyk02pxpc9w32ipw54y-a1388 URL: nar/1yz34sv97gchidalrisf2j7vsjv0rzfxhygs4qgizl42p3gx6q43.nar.zst1389 Compression: zstd1390 NarHash: sha256:1yz34sv97gchidalrisf2j7vsjv0rzfxhygs4qgizl42p3gx6q431391 NarSize: 2641392 References: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientPushesUseOnePush3281767447/001/store/81fb599qnxmadwqxdx6dhjkakcwhqqmx-shared-dep1393 CA: text:sha256:14hn3g6q6pd3i167dnxhg50088n7wsrrqcl2wmdlvb7gy8d9392m1394 client_pushes_test.go:97: Retrieved narinfo from S3:1395 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientPushesUseOnePush3281767447/001/store/7phv74v0mljlnvkqhckqixj2v4d2hpf2-b1396 URL: nar/1yz34sv97gchidalrisf2j7vsjv0rzfxhygs4qgizl42p3gx6q43.nar.zst1397 Compression: zstd1398 NarHash: sha256:1yz34sv97gchidalrisf2j7vsjv0rzfxhygs4qgizl42p3gx6q431399 NarSize: 2641400 References: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientPushesUseOnePush3281767447/001/store/81fb599qnxmadwqxdx6dhjkakcwhqqmx-shared-dep1401 CA: text:sha256:14hn3g6q6pd3i167dnxhg50088n7wsrrqcl2wmdlvb7gy8d9392m1402--- PASS: TestClientPushesUseOnePush (6.21s)14032026/10/07 06:23:16 INFO lead: acquired remote=192.0.2.1:12341404=== CONT TestGCTaskStore_StartNew1405--- PASS: TestGCTaskStore_StartNew (0.00s)1406=== CONT TestGCEndsOnShutdown1407=== RUN TestGCEndsOnShutdown/before_the_run1408=== PAUSE TestGCEndsOnShutdown/before_the_run1409=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1410=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1411=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1412=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1413=== CONT TestService_ReadAuthMiddleware14142026/10/07 06:23:16 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/07 06:23:16 INFO Received uploads request method=POST path=/api/pending_closures14162026/10/07 06:23:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14172026/10/07 06:23:16 INFO Uploading im2k6fc2gvi6x74wvpkwdd3aj3mis4hc-a (272B)14182026/10/07 06:23:16 INFO Uploading iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3-shared-dep (136B)14192026/10/07 06:23:16 WARN Failed to register uploaded object key=f41fj4xgxar8qib9ynahfbnass94vq16.ls error="server returned 404: 404 page not found\n"14202026/10/07 06:23:16 WARN Failed to register uploaded object key=iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3.ls error="server returned 404: 404 page not found\n"14212026/10/07 06:23:16 WARN Failed to register uploaded object key=im2k6fc2gvi6x74wvpkwdd3aj3mis4hc.ls error="server returned 404: 404 page not found\n"14222026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/008dnb8i7p6h93szad9ywasrshqf7d68yik3hc7gyys6rsnbzzby.nar.zst error="server returned 404: 404 page not found\n"14232026/10/07 06:23:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14242026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14252026/10/07 06:23:16 INFO Signed narinfos id=1 count=214262026/10/07 06:23:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14272026/10/07 06:23:16 INFO Signed narinfos id=2 count=214282026/10/07 06:23:16 INFO Uploading 4 narinfos1429=== NAME TestPinProtectsFromGC1430 client_integration_test.go:731: Pinned store path: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestPinProtectsFromGC4089091581/001/store/i42i65y3c088smm1mwss7ibqw3l0s2l3-pinned-file.txt1431 client_integration_test.go:732: Unpinned store path: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestPinProtectsFromGC4089091581/001/store/qdjb3h3hz8gplkgaql1iy70l1i8kc07f-unpinned-file.txt14322026/10/07 06:23:16 WARN Failed to register uploaded object key=im2k6fc2gvi6x74wvpkwdd3aj3mis4hc.narinfo error="server returned 404: 404 page not found\n"14332026/10/07 06:23:16 WARN Failed to register uploaded object key=f41fj4xgxar8qib9ynahfbnass94vq16.narinfo error="server returned 404: 404 page not found\n"14342026/10/07 06:23:16 WARN Failed to register uploaded object key=iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3.narinfo error="server returned 404: 404 page not found\n"14352026/10/07 06:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14362026/10/07 06:23:16 WARN Failed to register uploaded object key=iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3.narinfo error="server returned 404: 404 page not found\n"14372026/10/07 06:23:16 INFO Completed upload id=1 objects=6 duration=24.014125ms14382026/10/07 06:23:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14392026/10/07 06:23:16 INFO Completed upload id=2 objects=6 duration=1.0335ms14402026/10/07 06:23:16 INFO Upload complete. (314ms)1441=== NAME TestClientFallsBackToClosures1442 client_pushes_test.go:112: Retrieved narinfo from S3:1443 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientFallsBackToClosures3653543952/001/store/iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3-shared-dep1444 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1445 Compression: zstd1446 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821447 NarSize: 1361448 References: 1449 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1450 client_pushes_test.go:112: Retrieved narinfo from S3:1451 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientFallsBackToClosures3653543952/001/store/im2k6fc2gvi6x74wvpkwdd3aj3mis4hc-a1452 URL: nar/008dnb8i7p6h93szad9ywasrshqf7d68yik3hc7gyys6rsnbzzby.nar.zst1453 Compression: zstd1454 NarHash: sha256:008dnb8i7p6h93szad9ywasrshqf7d68yik3hc7gyys6rsnbzzby1455 NarSize: 2721456 References: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientFallsBackToClosures3653543952/001/store/iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3-shared-dep1457 CA: text:sha256:0a4dkcp5zij2a4l11by0pgmb8nhng6r7f682mr8msnpi2s3s8sav1458 client_pushes_test.go:112: Retrieved narinfo from S3:1459 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientFallsBackToClosures3653543952/001/store/f41fj4xgxar8qib9ynahfbnass94vq16-b1460 URL: nar/008dnb8i7p6h93szad9ywasrshqf7d68yik3hc7gyys6rsnbzzby.nar.zst1461 Compression: zstd1462 NarHash: sha256:008dnb8i7p6h93szad9ywasrshqf7d68yik3hc7gyys6rsnbzzby1463 NarSize: 2721464 References: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientFallsBackToClosures3653543952/001/store/iyvgh5kfzjrj3c8gkkz92nxr8ja26pd3-shared-dep1465 CA: text:sha256:0a4dkcp5zij2a4l11by0pgmb8nhng6r7f682mr8msnpi2s3s8sav1466--- PASS: TestClientFallsBackToClosures (7.04s)1467=== CONT TestService_AuthMiddleware_OIDC14682026/10/07 06:23:16 INFO Received push request method=POST path=/api/pushes14692026/10/07 06:23:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54497/oidc14702026/10/07 06:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14712026/10/07 06:23:16 INFO Uploading i42i65y3c088smm1mwss7ibqw3l0s2l3-pinned-file.txt (128B)14722026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14732026/10/07 06:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14742026/10/07 06:23:16 WARN Failed to register uploaded object key=i42i65y3c088smm1mwss7ibqw3l0s2l3.ls error="server returned 404: 404 page not found\n"14752026/10/07 06:23:16 INFO Signed narinfos id=1 count=114762026/10/07 06:23:16 INFO Uploading 1 narinfos14772026/10/07 06:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete14782026/10/07 06:23:16 WARN Failed to register uploaded object key=i42i65y3c088smm1mwss7ibqw3l0s2l3.narinfo error="server returned 404: 404 page not found\n"14792026/10/07 06:23:16 INFO Completed push id=1 objects=3 duration=24.475334ms14802026/10/07 06:23:16 INFO Upload complete. (246ms)14812026/10/07 06:23:16 INFO Received push request method=POST path=/api/pushes14822026/10/07 06:23:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/10/07 06:23:16 INFO Uploading qdjb3h3hz8gplkgaql1iy70l1i8kc07f-unpinned-file.txt (128B)14842026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14852026/10/07 06:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14862026/10/07 06:23:16 WARN Failed to register uploaded object key=qdjb3h3hz8gplkgaql1iy70l1i8kc07f.ls error="server returned 404: 404 page not found\n"14872026/10/07 06:23:16 INFO Signed narinfos id=2 count=114882026/10/07 06:23:16 INFO Uploading 1 narinfos14892026/10/07 06:23:16 INFO Received complete push request method=POST path=/api/pushes/2/complete14902026/10/07 06:23:16 WARN Failed to register uploaded object key=qdjb3h3hz8gplkgaql1iy70l1i8kc07f.narinfo error="server returned 404: 404 page not found\n"14912026/10/07 06:23:16 INFO Completed push id=2 objects=3 duration=910.75µs14922026/10/07 06:23:16 INFO Upload complete. (158ms)14932026/10/07 06:23:16 INFO Received push request method=POST path=/api/pushes14942026/10/07 06:23:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures14952026/10/07 06:23:16 INFO Garbage collection started14962026/10/07 06:23:16 INFO Aborted multipart uploads count=0 kept=014972026/10/07 06:23:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14982026/10/07 06:23:16 INFO Uploading 6myjy7gmjyyvmhibqz7wl6rxd3sg415m-shared-dep (136B)14992026/10/07 06:23:16 INFO Uploading cbl6hn1q9ccs587564h4dk7428sfk21j-top (280B)15002026/10/07 06:23:16 WARN Force mode enabled - objects will be deleted immediately without grace period15012026/10/07 06:23:16 WARN Failed to register uploaded object key=cbl6hn1q9ccs587564h4dk7428sfk21j.ls error="server returned 404: 404 page not found\n"15022026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15032026/10/07 06:23:16 WARN Failed to register uploaded object key=6myjy7gmjyyvmhibqz7wl6rxd3sg415m.ls error="server returned 404: 404 page not found\n"15042026/10/07 06:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15052026/10/07 06:23:16 WARN Failed to register uploaded object key=nar/03h99c3br69hqa7qh4nssx8xp2srfkblgksb074lnj8hgym6hlbs.nar.zst error="server returned 404: 404 page not found\n"15062026/10/07 06:23:16 INFO Signed narinfos id=1 count=215072026/10/07 06:23:16 INFO Uploading 2 narinfos15082026/10/07 06:23:16 INFO lead: acquired remote=192.0.2.1:123415092026/10/07 06:23:16 INFO lead: released remote=192.0.2.1:12341510--- PASS: TestLeadIncumbentAnnouncesAtOnce (5.63s)1511=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15122026/10/07 06:23:16 WARN Failed to register uploaded object key=cbl6hn1q9ccs587564h4dk7428sfk21j.narinfo error="server returned 404: 404 page not found\n"15132026/10/07 06:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete15142026/10/07 06:23:16 WARN Failed to register uploaded object key=6myjy7gmjyyvmhibqz7wl6rxd3sg415m.narinfo error="server returned 404: 404 page not found\n"15152026/10/07 06:23:16 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=015162026/10/07 06:23:16 INFO Completed push id=1 objects=6 duration=12.138375ms15172026/10/07 06:23:16 INFO Upload complete. (176ms)1518=== NAME TestClientSharedPathCommittedMidPush1519 client_integration_test.go:680: Retrieved narinfo from S3:1520 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientSharedPathCommittedMidPush3376880342/001/store/6myjy7gmjyyvmhibqz7wl6rxd3sg415m-shared-dep1521 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1522 Compression: zstd1523 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821524 NarSize: 1361525 References: 1526 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1527 client_integration_test.go:680: Retrieved narinfo from S3:1528 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientSharedPathCommittedMidPush3376880342/001/store/cbl6hn1q9ccs587564h4dk7428sfk21j-top1529 URL: nar/03h99c3br69hqa7qh4nssx8xp2srfkblgksb074lnj8hgym6hlbs.nar.zst1530 Compression: zstd1531 NarHash: sha256:03h99c3br69hqa7qh4nssx8xp2srfkblgksb074lnj8hgym6hlbs1532 NarSize: 2801533 References: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientSharedPathCommittedMidPush3376880342/001/store/6myjy7gmjyyvmhibqz7wl6rxd3sg415m-shared-dep1534 CA: text:sha256:1syhwh7750r2s2yhrpmmmjylrv5h537cx4gw0l58vpbbaank4nri15352026/10/07 06:23:16 INFO Vacuumed table table=pending_closures15362026/10/07 06:23:16 INFO Vacuumed table table=pending_objects15372026/10/07 06:23:17 INFO Vacuumed table table=multipart_uploads15382026/10/07 06:23:17 INFO Vacuumed table table=closures1539--- PASS: TestClientSharedPathCommittedMidPush (6.12s)1540=== CONT TestCommitRacingPendingCleanupKeepsObjects15412026/10/07 06:23:17 INFO Vacuumed table table=objects15422026/10/07 06:23:17 INFO lead: released remote=192.0.2.1:12341543=== NAME TestClientWithDependencies1544 client_integration_test.go:613: Built derivation: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientWithDependencies2843488920/001/store/8akds4530mi3b83nrlsnhyi98xw8ws92-test-script1545--- PASS: TestLeadEndsOnShutdown (6.53s)1546=== CONT TestPushWaitsForSweepHoldingRow1547=== NAME TestClientWithDependencies1548 client_integration_test.go:615: Found 1 dependencies (including self)1549=== NAME TestClientMultipleUploads1550 client_integration_test.go:358: Created store path 0: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientMultipleUploads649955143/001/store/imjv8zsdyazm5a0dlvnzm9ms5dihwgix-test-file-0.txt15512026/10/07 06:23:17 INFO lead: acquired remote=192.0.2.1:12341552 client_integration_test.go:358: Created store path 1: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientMultipleUploads649955143/001/store/fmv4xmrld0v1sl6rirhc1vzmlwgj7bc3-test-file-1.txt15532026/10/07 06:23:17 INFO Received push request method=POST path=/api/pushes15542026/10/07 06:23:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15552026/10/07 06:23:17 INFO Uploading 8akds4530mi3b83nrlsnhyi98xw8ws92-test-script (136B)15562026/10/07 06:23:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15572026/10/07 06:23:17 WARN Failed to register uploaded object key=log/gc59ksv7v1dzg2f3gb9mvpabsl9pscvm-test-script.drv error="server returned 404: 404 page not found\n"15582026/10/07 06:23:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15592026/10/07 06:23:17 WARN Failed to register uploaded object key=8akds4530mi3b83nrlsnhyi98xw8ws92.ls error="server returned 404: 404 page not found\n"15602026/10/07 06:23:17 INFO Signed narinfos id=1 count=115612026/10/07 06:23:17 INFO Uploading 1 narinfos15622026/10/07 06:23:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15632026/10/07 06:23:17 WARN Failed to register uploaded object key=8akds4530mi3b83nrlsnhyi98xw8ws92.narinfo error="server returned 404: 404 page not found\n"15642026/10/07 06:23:17 INFO Completed push id=1 objects=4 duration=37.224917ms15652026/10/07 06:23:17 INFO Upload complete. (191ms)1566 client_integration_test.go:358: Created store path 2: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientMultipleUploads649955143/001/store/57pyyj882s1qkwbj7hhqlgpp9qzrx92j-test-file-2.txt1567=== NAME TestClientWithDependencies1568 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientWithDependencies2843488920/001/store) requires matching store prefix1569--- PASS: TestDeleteClosuresRacingPins (9.40s)1570=== CONT TestService_AuthMiddleware_MTLSProxyHeader1571--- PASS: TestClientWithDependencies (6.37s)1572=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15732026/10/07 06:23:17 INFO Received push request method=POST path=/api/pushes15742026/10/07 06:23:17 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15752026/10/07 06:23:17 INFO Uploading fmv4xmrld0v1sl6rirhc1vzmlwgj7bc3-test-file-1.txt (160B)15762026/10/07 06:23:17 INFO Uploading imjv8zsdyazm5a0dlvnzm9ms5dihwgix-test-file-0.txt (160B)15772026/10/07 06:23:17 INFO Uploading 57pyyj882s1qkwbj7hhqlgpp9qzrx92j-test-file-2.txt (160B)15782026/10/07 06:23:17 WARN Failed to register uploaded object key=57pyyj882s1qkwbj7hhqlgpp9qzrx92j.ls error="server returned 404: 404 page not found\n"15792026/10/07 06:23:17 WARN Failed to register uploaded object key=fmv4xmrld0v1sl6rirhc1vzmlwgj7bc3.ls error="server returned 404: 404 page not found\n"15802026/10/07 06:23:17 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15812026/10/07 06:23:17 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15822026/10/07 06:23:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15832026/10/07 06:23:17 WARN Failed to register uploaded object key=imjv8zsdyazm5a0dlvnzm9ms5dihwgix.ls error="server returned 404: 404 page not found\n"15842026/10/07 06:23:17 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15852026/10/07 06:23:17 INFO Signed narinfos id=1 count=315862026/10/07 06:23:17 INFO Uploading 3 narinfos15872026/10/07 06:23:17 WARN Failed to register uploaded object key=imjv8zsdyazm5a0dlvnzm9ms5dihwgix.narinfo error="server returned 404: 404 page not found\n"15882026/10/07 06:23:17 WARN Failed to register uploaded object key=fmv4xmrld0v1sl6rirhc1vzmlwgj7bc3.narinfo error="server returned 404: 404 page not found\n"15892026/10/07 06:23:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15902026/10/07 06:23:17 WARN Failed to register uploaded object key=57pyyj882s1qkwbj7hhqlgpp9qzrx92j.narinfo error="server returned 404: 404 page not found\n"15912026/10/07 06:23:17 INFO Completed push id=1 objects=9 duration=14.615834ms15922026/10/07 06:23:17 INFO Upload complete. (188ms)1593=== NAME TestClientMultipleUploads1594 client_integration_test.go:369: Uploaded 3 paths in 252.768084ms1595=== NAME TestClientIntegration1596 client_integration_test.go:286: Created store path: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientIntegration1198387586/002/store/vahwpbbmp6gvd1q2k1jj7715diq1widw-test-file.txt1597=== RUN TestService_RequireScope_OIDC/builder_may_write1598=== PAUSE TestService_RequireScope_OIDC/builder_may_write1599=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1600=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1601=== RUN TestService_RequireScope_OIDC/ops_may_admin1602=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1603=== RUN TestService_RequireScope_OIDC/ops_may_not_write1604=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1605=== RUN TestService_RequireScope_OIDC/reader_may_not_write1606=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1607=== RUN TestService_RequireScope_OIDC/static_token_may_admin1608=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1609=== RUN TestService_RequireScope_OIDC/static_token_may_write1610=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1611=== RUN TestService_RequireScope_OIDC/reader_may_read1612=== PAUSE TestService_RequireScope_OIDC/reader_may_read1613=== RUN TestService_RequireScope_OIDC/writer_implies_read1614=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1615=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1616=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1617=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1618=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1619=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1620=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1621=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1622=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1623=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1624=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1625=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1626--- PASS: TestClientMultipleUploads (6.02s)1627=== CONT TestParseSingleRange/none1628=== CONT TestIsValidCachePath/narinfo1629=== CONT TestIsValidCachePath/leading_slash1630=== CONT TestParseSingleRange/start_far_past_EOF1631=== CONT TestParseSingleRange/start_past_EOF1632=== CONT TestParseSingleRange/single_byte1633=== CONT TestParseSingleRange/suffix_exceeds_size1634=== CONT TestParseSingleRange/suffix1635=== CONT TestParseSingleRange/end_clamped_to_size1636=== CONT TestParseSingleRange/open-ended1637=== CONT TestParseSingleRange/closed1638=== CONT TestParseSingleRange/malformed_end_before_start1639=== CONT TestParseSingleRange/malformed_both_empty1640=== CONT TestParseSingleRange/malformed_no_dash1641=== CONT TestParseSingleRange/multi-range_ignored1642=== CONT TestParseSingleRange/unknown_unit1643--- PASS: TestParseSingleRange (0.00s)1644 --- PASS: TestParseSingleRange/none (0.00s)1645 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1646 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1647 --- PASS: TestParseSingleRange/single_byte (0.00s)1648 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1649 --- PASS: TestParseSingleRange/suffix (0.00s)1650 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1651 --- PASS: TestParseSingleRange/open-ended (0.00s)1652 --- PASS: TestParseSingleRange/closed (0.00s)1653 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1654 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1655 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1656 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1657 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1658=== CONT TestIsValidCachePath/short_hash1659=== CONT TestIsValidCachePath/wrong_extension1660=== CONT TestIsValidCachePath/nix-cache-info1661=== CONT TestIsValidCachePath/empty1662=== CONT TestIsValidCachePath/random_path1663=== CONT TestIsValidCachePath/invalid_char_u1664=== CONT TestIsValidCachePath/invalid_char_e1665=== CONT TestIsValidCachePath/traversal_in_middle1666=== CONT TestIsValidCachePath/traversal_parent1667=== CONT TestIsValidCachePath/index.html1668=== CONT TestIsValidCachePath/nar_uncompressed1669=== CONT TestIsValidCachePath/realisation1670=== CONT TestIsValidCachePath/log1671=== CONT TestIsValidCachePath/ls1672=== CONT TestIsValidCachePath/nar_xz1673=== CONT TestIsValidCachePath/nar_bz21674=== CONT TestIsValidCachePath/nar_zst1675=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1676--- PASS: TestIsValidCachePath (0.00s)1677 --- PASS: TestIsValidCachePath/narinfo (0.00s)1678 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1679 --- PASS: TestIsValidCachePath/short_hash (0.00s)1680 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1681 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1682 --- PASS: TestIsValidCachePath/empty (0.00s)1683 --- PASS: TestIsValidCachePath/random_path (0.00s)1684 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1685 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1686 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1687 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1688 --- PASS: TestIsValidCachePath/index.html (0.00s)1689 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1690 --- PASS: TestIsValidCachePath/realisation (0.00s)1691 --- PASS: TestIsValidCachePath/log (0.00s)1692 --- PASS: TestIsValidCachePath/ls (0.00s)1693 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1694 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1695 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1696 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1697=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16982026/10/07 06:23:17 INFO Received uploads request method=POST path=/16992026/10/07 06:23:17 INFO Received push request method=POST path=/api/pushes17002026/10/07 06:23:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17012026/10/07 06:23:17 INFO Uploading vahwpbbmp6gvd1q2k1jj7715diq1widw-test-file.txt (152B)17022026/10/07 06:23:18 WARN Failed to register uploaded object key=vahwpbbmp6gvd1q2k1jj7715diq1widw.ls error="server returned 404: 404 page not found\n"17032026/10/07 06:23:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17042026/10/07 06:23:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17052026/10/07 06:23:18 INFO Signed narinfos id=1 count=117062026/10/07 06:23:18 INFO Uploading 1 narinfos17072026/10/07 06:23:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17082026/10/07 06:23:18 WARN Failed to register uploaded object key=vahwpbbmp6gvd1q2k1jj7715diq1widw.narinfo error="server returned 404: 404 page not found\n"17092026/10/07 06:23:18 INFO Completed push id=1 objects=3 duration=18.582875ms17102026/10/07 06:23:18 INFO Upload complete. (183ms)17112026/10/07 06:23:18 INFO All 1 paths already cached1712=== NAME TestClientIntegration1713 client_integration_test.go:312: Retrieved narinfo from S3:1714 StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientIntegration1198387586/002/store/vahwpbbmp6gvd1q2k1jj7715diq1widw-test-file.txt1715 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1716 Compression: zstd1717 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11718 NarSize: 1521719 References: 1720 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11721 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1722 client_integration_test.go:313: Decompressed .ls content (64 bytes):1723 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1724 client_integration_test.go:316: Testing garbage collection...17252026/10/07 06:23:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures17262026/10/07 06:23:18 INFO Garbage collection started17272026/10/07 06:23:18 INFO Aborted multipart uploads count=0 kept=017282026/10/07 06:23:18 WARN Force mode enabled - objects will be deleted immediately without grace period1729=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17302026/10/07 06:23:18 INFO Received request for more parts method=POST path=/17312026/10/07 06:23:18 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=01732=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17332026/10/07 06:23:18 INFO Received complete multipart upload request method=POST path=/1734--- PASS: TestCacheStatsHandler (5.51s)1735=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17362026/10/07 06:23:18 INFO Received uploads request method=POST path=/1737=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17382026/10/07 06:23:18 INFO Received complete multipart upload request method=POST path=/1739=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17402026/10/07 06:23:18 INFO Vacuumed table table=pending_closures17412026/10/07 06:23:18 INFO Received request for more parts method=POST path=/1742=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1743--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1744 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.42s)1745 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1746 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)17472026/10/07 06:23:18 INFO Received uploads request method=POST path=/1748=== CONT TestPendingClosureWriteTimeout/empty1749=== CONT TestIsValidUploadKey/unknown_type1750=== CONT TestIsValidUploadKey/empty_key1751=== CONT TestIsValidUploadKey/absolute1752=== CONT TestIsValidUploadKey/traversal_nar1753=== CONT TestIsValidUploadKey/traversal1754=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1755=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1756--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1760 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1761=== CONT TestIsValidUploadKey/narinfo1762=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1763=== CONT TestIsValidUploadKey/nix-cache-info1764=== CONT TestIsValidUploadKey/index.html1765=== CONT TestIsValidUploadKey/realisation_plus_in_output1766=== CONT TestIsValidUploadKey/build_log_equals1767=== CONT TestIsValidUploadKey/realisation1768=== CONT TestIsValidUploadKey/build_log_plus_in_name1769=== CONT TestIsValidUploadKey/build_log_home-manager_file1770=== CONT TestIsValidUploadKey/build_log1771=== CONT TestIsValidUploadKey/listing1772=== CONT TestIsValidUploadKey/nar_plain1773=== CONT TestIsValidUploadKey/build_log_question_mark1774=== CONT TestIsValidUploadKey/nar_zst1775=== CONT TestIsValidUploadKey/nar_xz1776--- PASS: TestIsValidUploadKey (0.00s)1777 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1778 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1779 --- PASS: TestIsValidUploadKey/absolute (0.00s)1780 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1781 --- PASS: TestIsValidUploadKey/traversal (0.00s)1782 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1783 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1784 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1785 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1786 --- PASS: TestIsValidUploadKey/index.html (0.00s)1787 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1788 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1789 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1790 --- PASS: TestIsValidUploadKey/realisation (0.00s)1791 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1792 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1793 --- PASS: TestIsValidUploadKey/build_log (0.00s)1794 --- PASS: TestIsValidUploadKey/listing (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1796 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1797 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1798 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1799=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1800=== CONT TestPendingClosureWriteTimeout/670k_objects1801=== CONT TestPendingClosureWriteTimeout/400_objects18022026/10/07 06:23:18 INFO Vacuumed table table=pending_objects1803=== CONT TestProxyWriteTimeout/narinfo1804=== CONT TestProxyWriteTimeout/unknown_size1805=== CONT TestProxyWriteTimeout/10_GiB_nar1806=== CONT TestProxyWriteTimeout/1_GiB_nar1807--- PASS: TestProxyWriteTimeout (0.00s)1808 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1809 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1810 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1811 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1812=== CONT TestServerTLSConfig/no_client_CA1813=== CONT TestServerTLSConfig/not_a_PEM_file18142026/10/07 06:23:18 INFO Vacuumed table table=multipart_uploads1815=== CONT TestServerTLSConfig/missing_CA_file1816--- PASS: TestServerTLSConfig (0.01s)1817 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1818 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1819 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1820=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18212026/10/07 06:23:18 INFO Vacuumed table table=closures18222026/10/07 06:23:18 INFO Vacuumed table table=objects18232026/10/07 06:23:18 INFO lead: released remote=192.0.2.1:12341824--- PASS: TestReadProxyRangeRequest (5.79s)1825=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18262026/10/07 06:23:18 INFO lead: acquired remote=192.0.2.1:12341827=== NAME TestClientCADerivations1828 client_ca_test.go:136: Built CA derivation: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientCADerivations3782117180/001/store/fflygyl91hba6swgrjr03k7libjgip8d-ca-test1829 client_ca_test.go:139: Found 1 dependencies (including self)18302026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes18312026/10/07 06:23:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018322026/10/07 06:23:18 INFO Received create pin request method=POST path=/api/pins/myapp18332026/10/07 06:23:18 INFO Received complete push request method=POST path=/api/pushes/1/complete18342026/10/07 06:23:18 INFO Created/updated pin name=myapp store_path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestPinProtectsFromGC4089091581/001/store/i42i65y3c088smm1mwss7ibqw3l0s2l3-pinned-file.txt narinfo_key=i42i65y3c088smm1mwss7ibqw3l0s2l3.narinfo18352026/10/07 06:23:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures18362026/10/07 06:23:18 INFO Garbage collection started18372026/10/07 06:23:18 INFO Aborted multipart uploads count=0 kept=018382026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes18392026/10/07 06:23:18 INFO Completed push id=1 objects=6 duration=40.671375ms1840--- PASS: TestPush_CompleteCommitsEveryRoot (5.85s)18412026/10/07 06:23:18 WARN Force mode enabled - objects will be deleted immediately without grace period1842=== CONT TestPush_RejectsBadRequests/no_roots18432026/10/07 06:23:18 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=018442026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes18452026/10/07 06:23:18 INFO Vacuumed table table=pending_closures1846=== CONT TestPush_RejectsBadRequests/bad_root18472026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes1848=== CONT TestPush_RejectsBadRequests/no_objects18492026/10/07 06:23:18 INFO Vacuumed table table=pending_objects18502026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes1851=== CONT TestPush_RejectsBadRequests/root_not_in_objects18522026/10/07 06:23:18 INFO Vacuumed table table=multipart_uploads18532026/10/07 06:23:18 INFO Received push request method=POST path=/api/pushes1854=== CONT TestClientErrorHandling/InvalidStorePath1855--- PASS: TestPush_RejectsBadRequests (6.37s)1856 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1857 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1858 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)1859 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)18602026/10/07 06:23:18 INFO Vacuumed table table=closures18612026/10/07 06:23:19 INFO Vacuumed table table=objects18622026/10/07 06:23:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18632026/10/07 06:23:19 INFO Uploading fflygyl91hba6swgrjr03k7libjgip8d-ca-test (144B)18642026/10/07 06:23:19 WARN Failed to register uploaded object key=fflygyl91hba6swgrjr03k7libjgip8d.ls error="server returned 404: 404 page not found\n"18652026/10/07 06:23:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18662026/10/07 06:23:19 WARN Failed to register uploaded object key=log/z9mqiiqigcv8yfbclxc8hwijw4n6rk9v-ca-test.drv error="server returned 404: 404 page not found\n"18672026/10/07 06:23:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18682026/10/07 06:23:19 INFO Signed narinfos id=1 count=118692026/10/07 06:23:19 INFO Uploading 1 narinfos18702026/10/07 06:23:19 INFO Received complete push request method=POST path=/api/pushes/1/complete18712026/10/07 06:23:19 WARN Failed to register uploaded object key=fflygyl91hba6swgrjr03k7libjgip8d.narinfo error="server returned 404: 404 page not found\n"18722026/10/07 06:23:19 INFO Completed push id=1 objects=4 duration=22.896875ms18732026/10/07 06:23:19 INFO Upload complete. (325ms)18742026/10/07 06:23:19 INFO Received push request method=POST path=/api/pushes1875=== NAME TestClientCADerivations1876 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientCADerivations3782117180/001/store/fflygyl91hba6swgrjr03k7libjgip8d-ca-test1877 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1878 Compression: zstd1879 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1880 NarSize: 1441881 References: 1882 Deriver: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientCADerivations3782117180/001/store/z9mqiiqigcv8yfbclxc8hwijw4n6rk9v-ca-test.drv1883 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1884 client_ca_test.go:185: Checking for realisation files in S3...1885 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1886 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1887--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.78s)1888=== CONT TestClientErrorHandling/ServerNotAvailable1889=== NAME TestClientCADerivations1890 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket74?endpoint=http://localhost:54217&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestClientCADerivations3782117180/001/store'1891 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11892--- PASS: TestClientCADerivations (6.82s)1893=== CONT TestClientErrorHandling/InvalidAuthToken1894--- PASS: TestService_ReadScope_PublicByDefault (5.31s)1895=== CONT TestResolveDBConnectionString/flag_wins1896=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1897=== CONT TestResolveDBConnectionString/nothing_configured1898=== CONT TestResolveDBConnectionString/missing_file_is_an_error1899=== CONT TestResolveDBConnectionString/file_when_flag_empty1900=== CONT TestCacheConfigHandler/full_config,_no_issuer1901=== CONT TestCacheConfigHandler/no_signing_keys1902=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1903--- PASS: TestResolveDBConnectionString (0.03s)1904 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1905 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1906 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1907 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1908 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1909=== CONT TestCacheConfigHandler/no_cache_url_configured1910--- PASS: TestCacheConfigHandler (0.00s)1911 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1912 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1913 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1914 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1915=== CONT TestGCEndsOnShutdown/before_the_run19162026/10/07 06:23:19 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/present19172026/10/07 06:23:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.65037ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1918--- PASS: TestReadRedirectUsesPublicS3URL (5.30s)1919=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19202026/10/07 06:23:19 INFO lead: released remote=192.0.2.1:12341921--- PASS: TestLeadElectsOneAndHandsOver (7.48s)1922=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19232026/10/07 06:23:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.133323ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19242026/10/07 06:23:19 INFO Received push request method=POST path=/api/pushes1925--- PASS: TestConnectWaitsForAPeerMigration (7.78s)1926=== CONT TestService_RequireScope_OIDC/builder_may_write1927=== CONT TestService_RequireScope_OIDC/reader_may_read1928=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1929=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19302026/10/07 06:23:20 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]1931=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1932=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1933=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1934=== CONT TestService_RequireScope_OIDC/writer_implies_read1935=== CONT TestService_RequireScope_OIDC/reader_may_not_write1936=== CONT TestService_RequireScope_OIDC/static_token_may_write1937=== CONT TestService_RequireScope_OIDC/static_token_may_admin1938=== CONT TestService_RequireScope_OIDC/ops_may_admin1939=== CONT TestService_RequireScope_OIDC/ops_may_not_write1940=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1941--- PASS: TestService_RequireScope_OIDC (5.47s)1942 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1956--- PASS: TestReadProxyDisabled (5.29s)19572026/10/07 06:23:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.918598ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19582026/10/07 06:23:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01959=== NAME TestClientIntegration1960 client_integration_test.go:323: Objects in database after GC:1961 client_integration_test.go:323: Successfully deleted all objects with GC --force19622026-10-07 06:23:20.274 UTC [29643] ERROR: Push does not exist: id=119632026-10-07 06:23:20.274 UTC [29643] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19642026-10-07 06:23:20.274 UTC [29643] STATEMENT: SELECT commit_push($1)1965--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (5.67s)1966--- PASS: TestClientIntegration (8.21s)1967--- PASS: TestReadRedirectNar (5.62s)1968--- PASS: TestReadRedirectKeepsNarinfoProxied (5.86s)1969=== NAME TestPinProtectsFromGC1970 client_integration_test.go:840: Pin successfully protected closure from garbage collection19712026/10/07 06:23:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.494490826s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1972--- PASS: TestPinProtectsFromGC (11.01s)19732026-10-07 06:23:21.025 UTC [27666] LOG: checkpoint starting: wal1974--- PASS: TestService_ReadAuthMiddleware (4.95s)1975=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1976=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1977=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1978=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1979=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1980=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1981=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1982=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1983=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1984=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1985=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19862026/10/07 06:23:21 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]1987=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19882026/10/07 06:23:21 WARN Authentication failed token_preview=eyJhbGciOi...gRmbwqtoxA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1989--- PASS: TestService_AuthMiddleware_OIDC (4.98s)1990 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1991 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1992 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)1993 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)19942026/10/07 06:23:21 INFO Aborted multipart uploads count=0 kept=019952026/10/07 06:23:21 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/07 06:23:21 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=019972026/10/07 06:23:21 INFO Vacuumed table table=pending_closures19982026/10/07 06:23:21 INFO Vacuumed table table=pending_objects19992026/10/07 06:23:21 INFO Vacuumed table table=multipart_uploads20002026/10/07 06:23:21 INFO Vacuumed table table=closures20012026/10/07 06:23:21 INFO Vacuumed table table=objects2002--- PASS: TestCommitRacingPendingCleanupKeepsObjects (4.88s)20032026/10/07 06:23:21 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20042026/10/07 06:23:21 WARN mTLS auth: bound subjects configured but subject DN unavailable20052026/10/07 06:23:21 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2006--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.99s)20072026/10/07 06:23:22 INFO Received uploads request method=POST path=/api/pending_closures2008--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.77s)20092026/10/07 06:23:22 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-config20102026/10/07 06:23:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.105427ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2011--- PASS: TestPushWaitsForSweepHoldingRow (5.52s)20122026/10/07 06:23:22 INFO Received uploads request method=POST path=/api/pending_closures20132026/10/07 06:23:22 INFO Aborted multipart uploads count=0 kept=020142026/10/07 06:23:22 WARN Force mode enabled - objects will be deleted immediately without grace period20152026/10/07 06:23:22 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=020162026/10/07 06:23:22 INFO Vacuumed table table=pending_closures20172026/10/07 06:23:22 INFO Vacuumed table table=pending_objects20182026/10/07 06:23:22 INFO Vacuumed table table=multipart_uploads20192026/10/07 06:23:22 INFO Vacuumed table table=closures20202026/10/07 06:23:22 INFO Vacuumed table table=objects20212026/10/07 06:23:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.77601ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20222026/10/07 06:23:22 INFO Received uploads request method=POST path=/api/pending_closures2023--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2024 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.41s)2025 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.23s)20262026/10/07 06:23:23 INFO Received uploads request method=POST path=/api/pending_closures20272026/10/07 06:23:23 INFO Aborted multipart uploads count=0 kept=020282026/10/07 06:23:23 WARN Force mode enabled - objects will be deleted immediately without grace period20292026/10/07 06:23:23 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=020302026/10/07 06:23:23 INFO Vacuumed table table=pending_closures20312026/10/07 06:23:23 INFO Vacuumed table table=pending_objects20322026/10/07 06:23:23 INFO Vacuumed table table=multipart_uploads20332026/10/07 06:23:23 INFO Vacuumed table table=closures20342026/10/07 06:23:23 INFO Vacuumed table table=objects2035--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2036 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (4.42s)2037 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (4.61s)20382026/10/07 06:23:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.434681ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/07 06:23:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2040--- PASS: TestPendingClosureWriteTimeout (0.00s)2041 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2042 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2043 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2044 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (5.33s)20452026/10/07 06:23:23 INFO Aborted multipart uploads count=0 kept=020462026/10/07 06:23:23 WARN Force mode enabled - objects will be deleted immediately without grace period20472026-10-07 06:23:23.774 UTC [29680] ERROR: canceling statement due to user request20482026-10-07 06:23:23.774 UTC [29680] STATEMENT: -- name: MarkStaleObjects :execrows2049 WITH RECURSIVE ct AS (2050 SELECT timezone('UTC', now()) AS now2051 ),2052 closure_reach AS (2053 -- Start with all closure keys2054 SELECT o.key, o.refs2055 FROM objects o2056 INNER JOIN closures c ON o.key = c.key2057 UNION2058 -- Recursively add all referenced objects2059 SELECT o.key, o.refs2060 FROM objects o2061 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2062 ),2063 reachable_objects AS (2064 SELECT DISTINCT key FROM closure_reach2065 ),2066 stale_objects AS (2067 SELECT o.key2068 FROM objects AS o, ct2069 WHERE2070 NOT EXISTS (2071 SELECT 12072 FROM reachable_objects ro2073 WHERE ro.key = o.key2074 )2075 AND NOT EXISTS (2076 SELECT 12077 FROM pending_objects AS po2078 WHERE po.key = o.key2079 )2080 AND o.deleted_at IS NULL -- Only mark fresh objects2081 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2082 FOR UPDATE2083 )2084 UPDATE objects2085 SET2086 deleted_at = ct.now,2087 first_deleted_at = COALESCE(first_deleted_at, ct.now)2088 FROM stale_objects, ct2089 WHERE objects.key = stale_objects.key2090 20912026/10/07 06:23:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20922026/10/07 06:23:23 INFO Aborted multipart uploads count=0 kept=020932026/10/07 06:23:23 WARN Force mode enabled - objects will be deleted immediately without grace period20942026/10/07 06:23:23 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:54217/bucket100/?delete=\": context canceled"2095--- PASS: TestGCEndsOnShutdown (0.00s)2096 --- PASS: TestGCEndsOnShutdown/before_the_run (4.00s)2097 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.13s)2098 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.25s)20992026/10/07 06:23:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.669872823s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21002026/10/07 06:23:25 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"21012026/10/07 06:23:25 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-config21022026/10/07 06:23:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.486013ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21032026/10/07 06:23:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.63966ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21042026/10/07 06:23:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=753.600349ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21052026/10/07 06:23:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.758506285s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21062026/10/07 06:23:28 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_closures21072026/10/07 06:23:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.967611ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21082026/10/07 06:23:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.523196ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21092026/10/07 06:23:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.297858ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21102026/10/07 06:23:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.680389057s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2111--- PASS: TestClientErrorHandling (0.00s)2112 --- PASS: TestClientErrorHandling/InvalidStorePath (4.33s)2113 --- PASS: TestClientErrorHandling/InvalidAuthToken (4.44s)2114 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.85s)2115PASS2116{"timestamp":"2026-10-07T06:23:32.068665Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54347","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}21172026-10-07 06:23:32.216 UTC [27661] LOG: received smart shutdown request21182026-10-07 06:23:32.218 UTC [27661] LOG: background worker "logical replication launcher" (PID 27671) exited with exit code 121192026-10-07 06:23:33.807 UTC [27666] LOG: checkpoint complete: wrote 10766 buffers (65.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=11.746 s, sync=0.919 s, total=12.782 s; sync files=34046, longest=0.002 s, average=0.001 s; distance=533373 kB, estimate=533373 kB; lsn=0/2289BB98, redo lsn=0/2206C43021202026-10-07 06:23:33.808 UTC [27666] LOG: shutting down21212026-10-07 06:23:33.808 UTC [27666] LOG: checkpoint starting: shutdown immediate21222026-10-07 06:23:33.899 UTC [27666] LOG: checkpoint complete: wrote 1216 buffers (7.4%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.079 s, sync=0.012 s, total=0.092 s; sync files=499, longest=0.001 s, average=0.001 s; distance=8381 kB, estimate=480874 kB; lsn=0/2289BC10, redo lsn=0/2289BC1021232026-10-07 06:23:33.908 UTC [27661] LOG: database system is shut down2124Running OIDC tests...2125=== RUN TestAudienceForIssuer2126=== PAUSE TestAudienceForIssuer2127=== RUN TestGlobMatch2128=== PAUSE TestGlobMatch2129=== RUN TestValidateToken_ValidToken2130=== PAUSE TestValidateToken_ValidToken2131=== RUN TestValidateToken_WrongAudience2132=== PAUSE TestValidateToken_WrongAudience2133=== RUN TestValidateToken_Expired2134=== PAUSE TestValidateToken_Expired2135=== RUN TestValidateToken_BoundClaimsMismatch2136=== PAUSE TestValidateToken_BoundClaimsMismatch2137=== RUN TestValidateToken_BoundSubjectMismatch2138=== PAUSE TestValidateToken_BoundSubjectMismatch2139=== RUN TestValidateToken_MultipleProviders2140=== PAUSE TestValidateToken_MultipleProviders2141=== RUN TestValidateToken_NoMatchingProvider2142=== PAUSE TestValidateToken_NoMatchingProvider2143=== RUN TestValidateToken_KubernetesServiceAccount2144=== PAUSE TestValidateToken_KubernetesServiceAccount2145=== RUN TestNewValidator_KubernetesRequiresCA2146=== PAUSE TestNewValidator_KubernetesRequiresCA2147=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2148=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2149=== RUN TestPins_ReservedForMatchingRule2150=== PAUSE TestPins_ReservedForMatchingRule2151=== RUN TestPins_TopLevelShorthand2152=== PAUSE TestPins_TopLevelShorthand2153=== RUN TestPins_ConfigValidation2154=== PAUSE TestPins_ConfigValidation2155=== RUN TestScopes_LegacyProviderDefaultsToWrite2156=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2157=== RUN TestScopes_Rules2158=== PAUSE TestScopes_Rules2159=== RUN TestScopes_ConfigValidation2160=== PAUSE TestScopes_ConfigValidation2161=== CONT TestAudienceForIssuer2162--- PASS: TestAudienceForIssuer (0.00s)2163=== CONT TestValidateToken_NoMatchingProvider2164=== CONT TestPins_ConfigValidation2165=== CONT TestValidateToken_KubernetesServiceAccount2166=== CONT TestPins_ReservedForMatchingRule2167=== CONT TestPins_TopLevelShorthand2168=== CONT TestScopes_Rules2169=== CONT TestValidateToken_Expired2170--- PASS: TestPins_ConfigValidation (0.00s)2171=== CONT TestScopes_LegacyProviderDefaultsToWrite2172=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2173=== CONT TestNewValidator_KubernetesRequiresCA2174=== CONT TestValidateToken_BoundSubjectMismatch2175=== CONT TestValidateToken_BoundClaimsMismatch2176=== CONT TestValidateToken_MultipleProviders2177=== CONT TestScopes_ConfigValidation2178=== CONT TestValidateToken_ValidToken2179--- PASS: TestScopes_ConfigValidation (0.00s)2180=== CONT TestGlobMatch2181=== RUN TestGlobMatch/foo_foo2182=== PAUSE TestGlobMatch/foo_foo2183=== RUN TestGlobMatch/foo_bar2184=== PAUSE TestGlobMatch/foo_bar2185=== RUN TestGlobMatch/*_2186=== PAUSE TestGlobMatch/*_2187=== RUN TestGlobMatch/*_anything2188=== PAUSE TestGlobMatch/*_anything2189=== RUN TestGlobMatch/foo*_foo2190=== PAUSE TestGlobMatch/foo*_foo2191=== RUN TestGlobMatch/foo*_foobar2192=== PAUSE TestGlobMatch/foo*_foobar2193=== RUN TestGlobMatch/foo*_bar2194=== PAUSE TestGlobMatch/foo*_bar2195=== RUN TestGlobMatch/*bar_bar2196=== PAUSE TestGlobMatch/*bar_bar2197=== RUN TestGlobMatch/*bar_foobar2198=== PAUSE TestGlobMatch/*bar_foobar2199=== RUN TestGlobMatch/*bar_foo2200=== PAUSE TestGlobMatch/*bar_foo2201=== RUN TestGlobMatch/foo*bar_foobar2202=== PAUSE TestGlobMatch/foo*bar_foobar2203=== RUN TestGlobMatch/foo*bar_foo123bar2204=== PAUSE TestGlobMatch/foo*bar_foo123bar2205=== RUN TestGlobMatch/foo*bar_foobarbaz2206=== PAUSE TestGlobMatch/foo*bar_foobarbaz2207=== RUN TestGlobMatch/*/*_foo/bar2208=== PAUSE TestGlobMatch/*/*_foo/bar2209=== RUN TestGlobMatch/*/*_foo2210=== PAUSE TestGlobMatch/*/*_foo2211=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2212=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2213=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02214=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02215=== RUN TestGlobMatch/refs/*/main_refs/heads/main2216=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2217=== RUN TestGlobMatch/fo?_foo2218=== PAUSE TestGlobMatch/fo?_foo2219=== RUN TestGlobMatch/fo?_fo2220=== PAUSE TestGlobMatch/fo?_fo2221=== RUN TestGlobMatch/fo?_fooo2222=== PAUSE TestGlobMatch/fo?_fooo2223=== RUN TestGlobMatch/?oo_foo2224=== PAUSE TestGlobMatch/?oo_foo2225=== RUN TestGlobMatch/?oo_boo2226=== PAUSE TestGlobMatch/?oo_boo2227=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2228=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2229=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2230=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2231=== CONT TestGlobMatch/foo_foo2232=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2233=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2234=== CONT TestGlobMatch/?oo_boo2235=== CONT TestGlobMatch/?oo_foo2236=== CONT TestGlobMatch/fo?_fooo2237=== CONT TestGlobMatch/fo?_fo2238=== CONT TestGlobMatch/fo?_foo2239=== CONT TestGlobMatch/refs/*/main_refs/heads/main2240=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02241=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2242=== CONT TestGlobMatch/*/*_foo2243=== CONT TestGlobMatch/*/*_foo/bar2244=== CONT TestGlobMatch/foo*bar_foobarbaz2245=== CONT TestGlobMatch/foo*bar_foo123bar2246=== CONT TestGlobMatch/foo*bar_foobar2247=== CONT TestGlobMatch/*bar_foo2248=== CONT TestGlobMatch/*bar_foobar2249=== CONT TestGlobMatch/*bar_bar2250=== CONT TestGlobMatch/foo*_bar2251=== CONT TestGlobMatch/foo*_foobar2252=== CONT TestGlobMatch/foo*_foo2253=== CONT TestGlobMatch/*_anything2254=== CONT TestGlobMatch/*_2255=== CONT TestGlobMatch/foo_bar2256--- PASS: TestGlobMatch (0.00s)2257 --- PASS: TestGlobMatch/foo_foo (0.00s)2258 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2259 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2260 --- PASS: TestGlobMatch/?oo_boo (0.00s)2261 --- PASS: TestGlobMatch/?oo_foo (0.00s)2262 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2263 --- PASS: TestGlobMatch/fo?_fo (0.00s)2264 --- PASS: TestGlobMatch/fo?_foo (0.00s)2265 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2266 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2267 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2268 --- PASS: TestGlobMatch/*/*_foo (0.00s)2269 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2270 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2271 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2272 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2273 --- PASS: TestGlobMatch/*bar_foo (0.00s)2274 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2275 --- PASS: TestGlobMatch/*bar_bar (0.00s)2276 --- PASS: TestGlobMatch/foo*_bar (0.00s)2277 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2278 --- PASS: TestGlobMatch/foo*_foo (0.00s)2279 --- PASS: TestGlobMatch/*_anything (0.00s)2280 --- PASS: TestGlobMatch/*_ (0.00s)2281 --- PASS: TestGlobMatch/foo_bar (0.00s)2282=== CONT TestValidateToken_WrongAudience22832026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54718/oidc2284--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)22852026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54725/oidc22862026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54721/oidc22872026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54722/oidc22882026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54723/oidc22892026/10/07 06:23:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54724/oidc2290--- PASS: TestValidateToken_ValidToken (0.13s)2291--- PASS: TestValidateToken_WrongAudience (0.13s)2292--- PASS: TestPins_ReservedForMatchingRule (0.15s)22932026/10/07 06:23:36 http: TLS handshake error from 127.0.0.1:54727: read tcp 127.0.0.1:54720->127.0.0.1:54727: use of closed network connection2294--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2295--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)2296--- PASS: TestScopes_Rules (0.16s)22972026/10/07 06:23:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54732/oidc2298--- PASS: TestValidateToken_BoundClaimsMismatch (0.16s)22992026/10/07 06:23:36 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:547342300--- PASS: TestValidateToken_KubernetesServiceAccount (0.19s)23012026/10/07 06:23:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54737/oidc2302--- PASS: TestPins_TopLevelShorthand (0.20s)23032026/10/07 06:23:36 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232304--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.22s)23052026/10/07 06:23:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54736/oidc2306--- PASS: TestValidateToken_NoMatchingProvider (0.25s)23072026/10/07 06:23:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54739/oidc23082026/10/07 06:23:36 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54744/oidc2309--- PASS: TestValidateToken_MultipleProviders (0.25s)23102026/10/07 06:23:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54747/oidc2311--- PASS: TestValidateToken_Expired (0.31s)2312PASS2313Running hook tests...2314=== RUN TestSendPathsEmpty2315=== PAUSE TestSendPathsEmpty2316=== RUN TestQueueEnqueueAndFetch2317=== PAUSE TestQueueEnqueueAndFetch2318=== RUN TestQueueDeduplication2319=== PAUSE TestQueueDeduplication2320=== RUN TestQueueRemove2321=== PAUSE TestQueueRemove2322=== RUN TestQueueFetchBatchLimit2323=== PAUSE TestQueueFetchBatchLimit2324=== RUN TestQueueRetryMovesToBack2325=== PAUSE TestQueueRetryMovesToBack2326=== RUN TestQueueFetchRemoveLifecycle2327=== PAUSE TestQueueFetchRemoveLifecycle2328=== RUN TestQueueConcurrentWriters2329=== PAUSE TestQueueConcurrentWriters2330=== RUN TestQueueRemoveLargeClosure2331=== PAUSE TestQueueRemoveLargeClosure2332=== RUN TestServerClientIntegration2333--- PASS: TestServerClientIntegration (0.00s)2334=== RUN TestServerQueueError23352026/10/07 06:23:36 ERROR Failed to queue paths error="permission denied" count=12336--- PASS: TestServerQueueError (0.00s)2337=== RUN TestGetListenerSocketActivation2338 server_test.go:146: systemd socket activation does not exist on darwin2339--- SKIP: TestGetListenerSocketActivation (0.00s)2340=== RUN TestDrainIsolatesPoisonPath2341=== PAUSE TestDrainIsolatesPoisonPath2342=== RUN TestRunNotBlockedByPoisonHead2343=== PAUSE TestRunNotBlockedByPoisonHead2344=== RUN TestDrainGivesUpWhenServerDown2345=== PAUSE TestDrainGivesUpWhenServerDown2346=== RUN TestFailedPathPrunedByLaterClosure2347=== PAUSE TestFailedPathPrunedByLaterClosure2348=== RUN TestWorkerUploadsAndRemoves2349=== PAUSE TestWorkerUploadsAndRemoves2350=== RUN TestWorkerSkipsGCdPaths2351=== PAUSE TestWorkerSkipsGCdPaths2352=== RUN TestWorkerPrunesClosureDeps2353=== PAUSE TestWorkerPrunesClosureDeps2354=== RUN TestDrainTimeout2355=== PAUSE TestDrainTimeout2356=== CONT TestSendPathsEmpty2357--- PASS: TestSendPathsEmpty (0.00s)2358=== CONT TestQueueRemoveLargeClosure2359=== CONT TestQueueFetchBatchLimit2360=== CONT TestDrainTimeout2361=== CONT TestWorkerPrunesClosureDeps2362=== CONT TestWorkerSkipsGCdPaths2363=== CONT TestWorkerUploadsAndRemoves2364=== CONT TestFailedPathPrunedByLaterClosure2365=== CONT TestDrainGivesUpWhenServerDown2366=== CONT TestRunNotBlockedByPoisonHead2367=== CONT TestQueueRetryMovesToBack2368=== CONT TestQueueRemove2369=== CONT TestDrainIsolatesPoisonPath2370=== CONT TestQueueConcurrentWriters2371=== CONT TestQueueFetchRemoveLifecycle2372=== CONT TestQueueEnqueueAndFetch2373=== CONT TestQueueDeduplication2374--- PASS: TestQueueEnqueueAndFetch (0.01s)23752026/10/07 06:23:36 INFO Uploading batch count=123762026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=123772026/10/07 06:23:36 INFO Uploading batch count=223782026/10/07 06:23:36 INFO Uploading batch count=123792026/10/07 06:23:36 INFO Upload queue status pending=323802026/10/07 06:23:36 INFO Uploading batch count=123812026/10/07 06:23:36 INFO Uploading batch count=123822026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=123832026/10/07 06:23:36 INFO Upload queue status pending=223842026/10/07 06:23:36 INFO Uploading batch count=22385--- PASS: TestQueueRetryMovesToBack (0.01s)2386--- PASS: TestQueueDeduplication (0.01s)2387--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23882026/10/07 06:23:36 INFO Uploading batch count=423892026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=42390--- PASS: TestQueueFetchBatchLimit (0.01s)2391--- PASS: TestQueueRemove (0.01s)23922026/10/07 06:23:36 INFO Upload queue status pending=223932026/10/07 06:23:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestWorkerSkipsGCdPaths1189938362/002/nonexistent23942026/10/07 06:23:36 INFO Uploading batch count=223952026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=223962026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/a23972026/10/07 06:23:36 INFO Uploading batch count=123982026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/b23992026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainIsolatesPoisonPath170732255/002/bbb2400--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24012026/10/07 06:23:36 INFO Upload queue status pending=224022026/10/07 06:23:36 INFO Uploading batch count=224032026/10/07 06:23:36 INFO Uploading batch count=124042026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=224052026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/c24062026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/d24072026/10/07 06:23:36 INFO Uploading batch count=124082026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=124092026/10/07 06:23:36 INFO Uploading batch count=224102026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=224112026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/e24122026/10/07 06:23:36 INFO Uploading batch count=124132026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=124142026/10/07 06:23:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestDrainGivesUpWhenServerDown2573110901/002/f24152026/10/07 06:23:36 INFO Uploading batch count=124162026/10/07 06:23:36 ERROR Upload failed error="upload failed" count=124172026/10/07 06:23:36 ERROR Drain finished with paths left in queue remaining=1024182026/10/07 06:23:36 ERROR Drain finished with paths left in queue remaining=12419--- PASS: TestDrainIsolatesPoisonPath (0.02s)2420--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2421--- PASS: TestWorkerUploadsAndRemoves (0.03s)2422--- PASS: TestWorkerPrunesClosureDeps (0.03s)2423--- PASS: TestWorkerSkipsGCdPaths (0.03s)2424--- PASS: TestQueueRemoveLargeClosure (0.05s)2425--- PASS: TestQueueConcurrentWriters (0.13s)24262026/10/07 06:23:36 ERROR Upload failed error="context deadline exceeded" count=224272026/10/07 06:23:36 ERROR Drain finished with paths left in queue remaining=42428--- PASS: TestDrainTimeout (0.21s)24292026/10/07 06:23:37 INFO Uploading batch count=124302026/10/07 06:23:37 INFO Uploading batch count=124312026/10/07 06:23:37 INFO Uploading batch count=124322026/10/07 06:23:37 ERROR Upload failed error="upload failed" count=124332026/10/07 06:23:37 INFO Uploading batch count=124342026/10/07 06:23:37 ERROR Upload failed error="upload failed" count=124352026/10/07 06:23:37 INFO Uploading batch count=124362026/10/07 06:23:37 ERROR Upload failed error="upload failed" count=124372026/10/07 06:23:37 INFO Uploading batch count=124382026/10/07 06:23:37 ERROR Upload failed error="upload failed" count=124392026/10/07 06:23:37 ERROR Drain finished with paths left in queue remaining=12440--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2441PASS2442Running signing tests...2443=== RUN TestExternalSigner2444=== PAUSE TestExternalSigner2445=== RUN TestExternalSignerWrongPublicKey2446=== PAUSE TestExternalSignerWrongPublicKey2447=== RUN TestExternalSignerErrors2448=== PAUSE TestExternalSignerErrors2449=== RUN TestExternalSignerRestartsAfterCrash2450=== PAUSE TestExternalSignerRestartsAfterCrash2451=== RUN TestExternalSignerProgramErrorKeepsProcess2452=== PAUSE TestExternalSignerProgramErrorKeepsProcess2453=== RUN TestExternalSignerClose2454=== PAUSE TestExternalSignerClose2455=== RUN TestExternalSignerRejectsInvalidPublicKey2456=== PAUSE TestExternalSignerRejectsInvalidPublicKey2457=== RUN TestExternalSignerCancellation2458=== PAUSE TestExternalSignerCancellation2459=== RUN TestGenerateFingerprint2460=== PAUSE TestGenerateFingerprint2461=== RUN TestParseSigningKey2462=== PAUSE TestParseSigningKey2463=== RUN TestSign2464=== PAUSE TestSign2465=== RUN TestSignBatch2466=== PAUSE TestSignBatch2467=== RUN TestNilKeyPublicKey2468=== PAUSE TestNilKeyPublicKey2469=== RUN TestSignErrors2470=== PAUSE TestSignErrors2471=== CONT TestExternalSigner2472=== CONT TestExternalSignerCancellation2473=== CONT TestSignBatch2474=== CONT TestExternalSignerProgramErrorKeepsProcess2475=== CONT TestParseSigningKey2476=== RUN TestParseSigningKey/valid_32-byte_key2477=== PAUSE TestParseSigningKey/valid_32-byte_key2478=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2479=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2480=== RUN TestParseSigningKey/no_colon2481=== PAUSE TestParseSigningKey/no_colon2482=== RUN TestParseSigningKey/empty_name2483=== PAUSE TestParseSigningKey/empty_name2484=== RUN TestParseSigningKey/invalid_base642485=== PAUSE TestParseSigningKey/invalid_base642486=== RUN TestParseSigningKey/wrong_length2487=== PAUSE TestParseSigningKey/wrong_length2488=== CONT TestParseSigningKey/valid_32-byte_key2489=== CONT TestExternalSignerErrors2490=== CONT TestExternalSignerRejectsInvalidPublicKey2491=== RUN TestExternalSignerRejectsInvalidPublicKey/#002492=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002493=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2494=== CONT TestExternalSignerWrongPublicKey2495=== RUN TestExternalSignerErrors/exit_at_startup2496=== PAUSE TestExternalSignerErrors/exit_at_startup2497=== RUN TestExternalSignerErrors/null_signatures2498=== PAUSE TestExternalSignerErrors/null_signatures2499=== RUN TestExternalSignerErrors/wrong_signature_name2500=== PAUSE TestExternalSignerErrors/wrong_signature_name2501=== RUN TestExternalSignerErrors/invalid_signature_base642502=== PAUSE TestExternalSignerErrors/invalid_signature_base642503=== RUN TestExternalSignerErrors/program_error2504=== PAUSE TestExternalSignerErrors/program_error2505=== RUN TestExternalSignerErrors/exit_on_request2506=== PAUSE TestExternalSignerErrors/exit_on_request2507=== RUN TestExternalSignerErrors/null2508=== PAUSE TestExternalSignerErrors/null2509=== RUN TestExternalSignerErrors/too_few_signatures2510=== PAUSE TestExternalSignerErrors/too_few_signatures2511=== RUN TestExternalSignerErrors/missing_signature_name2512=== PAUSE TestExternalSignerErrors/missing_signature_name2513=== RUN TestExternalSignerErrors/invalid_JSON2514=== PAUSE TestExternalSignerErrors/invalid_JSON2515=== RUN TestExternalSignerErrors/wrong_shape2516=== PAUSE TestExternalSignerErrors/wrong_shape2517=== RUN TestExternalSignerErrors/wrong_id2518=== PAUSE TestExternalSignerErrors/wrong_id2519=== RUN TestExternalSignerErrors/missing_signatures2520=== PAUSE TestExternalSignerErrors/missing_signatures2521=== RUN TestExternalSignerErrors/wrong_signatures_shape2522=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2523=== RUN TestExternalSignerErrors/unrequested_key2524=== PAUSE TestExternalSignerErrors/unrequested_key2525=== RUN TestExternalSignerErrors/wrong_signature_length2526=== PAUSE TestExternalSignerErrors/wrong_signature_length2527=== CONT TestExternalSignerErrors/exit_at_startup2528=== CONT TestExternalSignerErrors/missing_signature_name2529=== CONT TestExternalSignerErrors/missing_signatures2530=== CONT TestExternalSignerErrors/too_few_signatures2531=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2532=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2533=== CONT TestParseSigningKey/wrong_length2534=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2535=== CONT TestExternalSignerErrors/wrong_id2536=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2537=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2538=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2539=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2540=== CONT TestExternalSignerErrors/wrong_shape2541=== CONT TestParseSigningKey/invalid_base642542=== CONT TestExternalSignerErrors/unrequested_key2543=== CONT TestParseSigningKey/empty_name2544=== CONT TestExternalSignerErrors/wrong_signature_length2545=== CONT TestParseSigningKey/no_colon2546=== CONT TestExternalSignerErrors/invalid_JSON2547=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2548=== CONT TestGenerateFingerprint2549=== RUN TestGenerateFingerprint/basic_with_references2550=== PAUSE TestGenerateFingerprint/basic_with_references2551=== RUN TestGenerateFingerprint/no_references2552=== PAUSE TestGenerateFingerprint/no_references2553=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2554=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2555=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2556=== CONT TestSignErrors2557=== CONT TestExternalSignerRestartsAfterCrash2558=== CONT TestSign2559=== CONT TestExternalSignerClose2560=== CONT TestNilKeyPublicKey2561--- PASS: TestNilKeyPublicKey (0.00s)2562=== CONT TestExternalSignerErrors/wrong_signatures_shape2563=== CONT TestExternalSignerErrors/program_error2564=== CONT TestExternalSignerErrors/exit_on_request2565=== CONT TestExternalSignerErrors/invalid_signature_base642566--- PASS: TestParseSigningKey (0.00s)2567 --- PASS: TestParseSigningKey/wrong_length (0.00s)2568 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2569 --- PASS: TestParseSigningKey/empty_name (0.00s)2570 --- PASS: TestParseSigningKey/no_colon (0.00s)2571 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2572 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2573=== RUN TestSignErrors/nil_key2574=== PAUSE TestSignErrors/nil_key2575=== RUN TestSignErrors/nil_narinfo2576=== PAUSE TestSignErrors/nil_narinfo2577=== RUN TestSignErrors/invalid_narinfo2578=== PAUSE TestSignErrors/invalid_narinfo2579=== RUN TestSignErrors/canceled2580=== PAUSE TestSignErrors/canceled2581=== CONT TestExternalSignerErrors/wrong_signature_name2582=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2583=== RUN TestGenerateFingerprint/invalid_nar_hash_length2584=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2585=== RUN TestGenerateFingerprint/invalid_store_path_prefix2586--- PASS: TestSign (0.00s)2587=== CONT TestExternalSignerErrors/null2588=== CONT TestExternalSignerErrors/null_signatures2589=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2590=== RUN TestGenerateFingerprint/invalid_reference_prefix2591=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2592=== CONT TestExternalSignerRejectsInvalidPublicKey/#002593=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2594=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2595=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2596=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2597--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2598 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2599 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2600 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2601 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2602 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2603=== CONT TestSignErrors/nil_key2604=== CONT TestSignErrors/canceled2605=== CONT TestSignErrors/invalid_narinfo2606=== CONT TestSignErrors/nil_narinfo2607--- PASS: TestSignBatch (0.00s)2608--- PASS: TestSignErrors (0.00s)2609 --- PASS: TestSignErrors/nil_key (0.00s)2610 --- PASS: TestSignErrors/canceled (0.00s)2611 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2612 --- PASS: TestSignErrors/nil_narinfo (0.00s)2613=== CONT TestGenerateFingerprint/basic_with_references2614=== CONT TestGenerateFingerprint/invalid_nar_hash_length2615=== CONT TestGenerateFingerprint/invalid_store_path_prefix2616=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2617=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2618=== CONT TestGenerateFingerprint/no_references2619=== CONT TestGenerateFingerprint/invalid_reference_prefix2620--- PASS: TestGenerateFingerprint (0.00s)2621 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2622 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2623 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2624 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2625 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2626 --- PASS: TestGenerateFingerprint/no_references (0.00s)2627 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2628--- PASS: TestExternalSignerCancellation (0.22s)2629--- PASS: TestExternalSignerRestartsAfterCrash (1.38s)2630/private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestExternalSignerRestartsAfterCrash2156627910/001/sign program: line 7: /private/var/lib/tribuchet/a6/scratch/7daf46bdce8694ec/build/TestExternalSignerRestartsAfterCrash2156627910/001/sign program.starts: No such file or directory2631--- PASS: TestExternalSignerWrongPublicKey (2.40s)2632--- PASS: TestExternalSigner (2.80s)2633--- PASS: TestExternalSignerClose (3.37s)2634--- PASS: TestExternalSignerProgramErrorKeepsProcess (3.77s)2635--- PASS: TestExternalSignerErrors (0.00s)2636 --- PASS: TestExternalSignerErrors/invalid_JSON (0.40s)2637 --- PASS: TestExternalSignerErrors/null (0.59s)2638 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.78s)2639 --- PASS: TestExternalSignerErrors/program_error (0.97s)2640 --- PASS: TestExternalSignerErrors/null_signatures (1.16s)2641 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.78s)2642 --- PASS: TestExternalSignerErrors/missing_signature_name (1.98s)2643 --- PASS: TestExternalSignerErrors/unrequested_key (2.59s)2644 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.98s)2645 --- PASS: TestExternalSignerErrors/exit_at_startup (3.18s)2646 --- PASS: TestExternalSignerErrors/wrong_id (3.56s)2647 --- PASS: TestExternalSignerErrors/missing_signatures (3.96s)2648 --- PASS: TestExternalSignerErrors/too_few_signatures (4.15s)2649 --- PASS: TestExternalSignerErrors/wrong_signature_name (4.33s)2650 --- PASS: TestExternalSignerErrors/exit_on_request (4.55s)2651 --- PASS: TestExternalSignerErrors/wrong_shape (4.74s)2652PASS2653Running OpenBao signer tests...2654=== RUN TestSign2655=== PAUSE TestSign2656=== RUN TestSignErrors2657=== PAUSE TestSignErrors2658=== RUN TestServe2659=== PAUSE TestServe2660=== RUN TestServeRejectsGarbage2661=== PAUSE TestServeRejectsGarbage2662=== CONT TestSign2663=== CONT TestSignErrors2664=== CONT TestServe2665=== CONT TestServeRejectsGarbage2666=== RUN TestSignErrors/no_prefix2667=== PAUSE TestSignErrors/no_prefix2668--- PASS: TestServeRejectsGarbage (0.00s)2669=== RUN TestSignErrors/invalid_base642670=== PAUSE TestSignErrors/invalid_base642671=== RUN TestSignErrors/http_error2672=== PAUSE TestSignErrors/http_error2673=== RUN TestSignErrors/invalid_json2674=== PAUSE TestSignErrors/invalid_json2675=== CONT TestSignErrors/no_prefix2676=== CONT TestSignErrors/http_error2677=== CONT TestSignErrors/invalid_base642678--- PASS: TestServe (0.00s)2679=== CONT TestSignErrors/invalid_json2680--- PASS: TestSignErrors (0.00s)2681 --- PASS: TestSignErrors/invalid_base64 (0.00s)2682 --- PASS: TestSignErrors/http_error (0.00s)2683 --- PASS: TestSignErrors/invalid_json (0.00s)2684 --- PASS: TestSignErrors/no_prefix (0.00s)2685--- PASS: TestSign (0.00s)2686PASS

succeeded niks3-go-unit-tests checks.aarch64-darwin.go-unit-tests · build #393 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #393 · raw