niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #357
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestParsePathInfoJSONMultiplePaths101=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths102=== CONT TestUploadMultipart_PartsInParallel103=== CONT TestDumpPathWriterError104=== CONT TestDumpPathSingleFile105=== CONT TestDumpPathMatchesNix106=== CONT TestEncodeNixBase32107=== RUN TestEncodeNixBase32/test_string_hash108=== PAUSE TestEncodeNixBase32/test_string_hash109=== RUN TestEncodeNixBase32/empty_input110=== PAUSE TestEncodeNixBase32/empty_input111=== CONT TestPathInfoHashCompatibility112=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)113=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)114=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon115=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon116=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI117=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI118=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512119=== CONT TestParsePathInfoJSON120=== RUN TestParsePathInfoJSON/Nix_format121=== PAUSE TestParsePathInfoJSON/Nix_format122=== RUN TestParsePathInfoJSON/Lix_format123=== PAUSE TestParsePathInfoJSON/Lix_format124=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica125=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths127=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512128=== RUN TestParsePathInfoJSON/empty_input129=== CONT TestGetStorePathHash130=== PAUSE TestParsePathInfoJSON/empty_input131=== RUN TestParsePathInfoJSON/whitespace_only132=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths133=== RUN TestGetStorePathHash/valid_store_path134=== PAUSE TestGetStorePathHash/valid_store_path135=== RUN TestGetStorePathHash/basename_without_hyphen_should_error136=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error137=== PAUSE TestParsePathInfoJSON/whitespace_only138=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error139=== RUN TestParsePathInfoJSON/invalid_JSON140=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error141=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error142=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error143=== CONT TestRegisterUploadedObjectReusesConnections144=== PAUSE TestParsePathInfoJSON/invalid_JSON145=== CONT TestConvertHashToNix32146=== CONT TestEncodeNixBase32WithRealHash147=== RUN TestConvertHashToNix32/SRI_format_to_Nix32148=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32149=== RUN TestConvertHashToNix32/already_Nix32_format150=== PAUSE TestConvertHashToNix32/already_Nix32_format151=== RUN TestConvertHashToNix32/invalid_format152=== PAUSE TestConvertHashToNix32/invalid_format153=== CONT TestUploadMultipart_SupersededByPeer154=== RUN TestUploadMultipart_SupersededByPeer/exists155=== PAUSE TestUploadMultipart_SupersededByPeer/exists156=== RUN TestUploadMultipart_SupersededByPeer/missing157=== PAUSE TestUploadMultipart_SupersededByPeer/missing158=== CONT TestPartSizeForNAR159=== RUN TestPartSizeForNAR/zero_stays_at_minimum160=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum161=== RUN TestPartSizeForNAR/small_stays_at_minimum162=== PAUSE TestPartSizeForNAR/small_stays_at_minimum163=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum164=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum165=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts166=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts167=== RUN TestPartSizeForNAR/1_TiB168--- PASS: TestEncodeNixBase32WithRealHash (0.00s)169=== PAUSE TestPartSizeForNAR/1_TiB170=== CONT TestRateLimiterFeedback171=== RUN TestPartSizeForNAR/5_TiB_S3_max_object172=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object173=== RUN TestPartSizeForNAR/capped_at_5_GiB174=== PAUSE TestPartSizeForNAR/capped_at_5_GiB175=== RUN TestRateLimiterFeedback/429_enables_limiter176=== PAUSE TestRateLimiterFeedback/429_enables_limiter177=== RUN TestRateLimiterFeedback/503_enables_limiter178=== PAUSE TestRateLimiterFeedback/503_enables_limiter179=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter180=== CONT TestPathInfoCACompatibility181=== RUN TestPathInfoCACompatibility/null_ca_field182=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter183=== PAUSE TestPathInfoCACompatibility/null_ca_field184=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter185=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter186=== RUN TestPathInfoCACompatibility/old_string_format_-_text187=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text188=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive189=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive190=== RUN TestPathInfoCACompatibility/new_structured_format_-_text191=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text192=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method193=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method194=== CONT TestSetClientTLSErrors195--- PASS: TestDoServerRequestAttachesToken (0.01s)196=== CONT TestStreamPushGivesUpOnDeadServer1972026/10/05 11:18:44 ERROR Upload failed error="connection refused" count=201982026/10/05 11:18:44 ERROR Server seems unavailable, giving up on batch untried=17199--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)200=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2012026/10/05 11:18:44 INFO Garbage collection started2022026/10/05 11:18:44 WARN Rate limiter enabled after throttle name=server-test rate=52032026/10/05 11:18:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53392204=== CONT TestFilterOversizedClosures2052026/10/05 11:18:44 WARN Rate limiter backed off name=server-test rate=52062026/10/05 11:18:44 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53392207=== RUN TestFilterOversizedClosures/no_limit_keeps_everything208=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything209=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped211=== RUN TestFilterOversizedClosures/all_closures_skipped212=== PAUSE TestFilterOversizedClosures/all_closures_skipped213=== CONT TestSetClientTLS214=== RUN TestSetClientTLSErrors/missing_cert_file215=== PAUSE TestSetClientTLSErrors/missing_cert_file216=== RUN TestSetClientTLSErrors/missing_key_file217=== PAUSE TestSetClientTLSErrors/missing_key_file218=== RUN TestSetClientTLSErrors/missing_ca_file219=== PAUSE TestSetClientTLSErrors/missing_ca_file220=== RUN TestSetClientTLSErrors/invalid_ca_file221=== PAUSE TestSetClientTLSErrors/invalid_ca_file222=== CONT TestClientSignaturesByStorePath223--- PASS: TestClientSignaturesByStorePath (0.00s)224=== CONT TestStreamPushReportsSignatures2252026/10/05 11:18:44 ERROR Upload failed error=boom count=1226--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)227=== CONT TestStreamPushRequestLine228--- PASS: TestStreamPushReportsSignatures (0.00s)229=== CONT TestCaseHackSuffix230=== RUN TestSetClientTLS/rejects_connection_without_client_cert231=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert232=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA233=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA234=== RUN TestSetClientTLS/preserves_debug_logging_transport235=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2362026/10/05 11:18:44 ERROR Upload failed error=boom count=1237=== CONT TestStreamPushReportsEveryPath238=== CONT TestStreamPushIsolatesFailures239--- PASS: TestStreamPushReportsEveryPath (0.00s)240=== CONT TestStreamPushBatchesUnderLoad2412026/10/05 11:18:44 ERROR Upload failed error="bad path" count=3242--- PASS: TestStreamPushIsolatesFailures (0.00s)243=== CONT TestShellSplitErrors244--- PASS: TestShellSplitErrors (0.00s)245=== CONT TestResolveStorePath246--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)2472026/10/05 11:18:44 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=02482026/10/05 11:18:44 WARN Garbage collection finished on another replica. Its statistics are not available here249--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)250=== CONT TestShellSplit251--- PASS: TestShellSplit (0.00s)252=== CONT TestScriptTokenNoExpiryRerunsEveryCall253--- PASS: TestResolveStorePath (0.01s)254=== CONT TestScriptTokenScriptFails255--- PASS: TestScriptTokenScriptFails (0.01s)256=== CONT TestScriptTokenBadJSON257--- PASS: TestStreamPushRequestLine (0.02s)258=== CONT TestScriptTokenEmptyToken259--- PASS: TestScriptTokenBadJSON (0.02s)260=== CONT TestScriptTokenCachesUntilRefresh261--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)262=== CONT TestFileTokenMissing263--- PASS: TestFileTokenMissing (0.00s)264=== CONT TestFileTokenEmpty265--- PASS: TestFileTokenEmpty (0.00s)266=== CONT TestFileTokenReadsAndCaches267--- PASS: TestFileTokenReadsAndCaches (0.00s)268=== CONT TestStaticToken269--- PASS: TestStaticToken (0.00s)270=== CONT TestScriptTokenEmptyCommand271--- PASS: TestScriptTokenEmptyCommand (0.00s)272=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2732026/10/05 11:18:44 WARN Rate limiter enabled after throttle name=server-test rate=5274--- PASS: TestScriptTokenEmptyToken (0.02s)275=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2762026/10/05 11:18:44 INFO Garbage collection started277--- PASS: TestDumpPathWriterError (0.05s)278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestEncodeNixBase32/empty_input280=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)281--- PASS: TestEncodeNixBase32 (0.00s)282 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)283 --- PASS: TestEncodeNixBase32/empty_input (0.00s)284=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512285=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon286=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI287--- PASS: TestPathInfoHashCompatibility (0.00s)288 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)289 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)290 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)291 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)292=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths293=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths294--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)295 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)296 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)297=== CONT TestGetStorePathHash/valid_store_path298=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error299=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error300=== CONT TestGetStorePathHash/basename_without_hyphen_should_error301--- PASS: TestGetStorePathHash (0.00s)302 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)303 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)304 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)305 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)306=== CONT TestParsePathInfoJSON/Nix_format307=== CONT TestConvertHashToNix32/SRI_format_to_Nix32308=== CONT TestConvertHashToNix32/invalid_format309=== CONT TestUploadMultipart_SupersededByPeer/exists310--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)311=== CONT TestConvertHashToNix32/already_Nix32_format312--- PASS: TestConvertHashToNix32 (0.00s)313 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)314 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)315 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)316=== CONT TestUploadMultipart_SupersededByPeer/missing317=== CONT TestParsePathInfoJSON/whitespace_only318=== CONT TestParsePathInfoJSON/invalid_JSON319=== CONT TestParsePathInfoJSON/Lix_format320=== CONT TestParsePathInfoJSON/empty_input321=== CONT TestPartSizeForNAR/zero_stays_at_minimum322=== CONT TestPartSizeForNAR/1_TiB323=== CONT TestPartSizeForNAR/capped_at_5_GiB324=== CONT TestPartSizeForNAR/5_TiB_S3_max_object325=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum326=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts327=== CONT TestPartSizeForNAR/small_stays_at_minimum328=== CONT TestRateLimiterFeedback/429_enables_limiter329--- PASS: TestParsePathInfoJSON (0.00s)330 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)331 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335--- PASS: TestPartSizeForNAR (0.00s)336 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)338 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)339 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)340 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)341 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)342 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3432026/10/05 11:18:44 WARN Rate limiter enabled after throttle name=server-test rate=5344--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)347=== CONT TestPathInfoCACompatibility/null_ca_field3482026/10/05 11:18:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:53477349=== CONT TestFilterOversizedClosures/no_limit_keeps_everything350=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3512026/10/05 11:18:44 WARN Rate limiter backed off name=server-test rate=5352=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter353=== CONT TestRateLimiterFeedback/503_enables_limiter3542026/10/05 11:18:44 WARN Rate limiter enabled after throttle name=server-test rate=53552026/10/05 11:18:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:53482356=== CONT TestSetClientTLSErrors/missing_cert_file357=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method358=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3592026/10/05 11:18:44 WARN Rate limiter backed off name=server-test rate=5360=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive361=== CONT TestPathInfoCACompatibility/old_string_format_-_text362--- PASS: TestPathInfoCACompatibility (0.00s)363 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)366 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)368=== CONT TestSetClientTLSErrors/invalid_ca_file369--- PASS: TestRateLimiterFeedback (0.00s)370 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)374=== CONT TestSetClientTLSErrors/missing_ca_file375=== CONT TestSetClientTLSErrors/missing_key_file376=== CONT TestFilterOversizedClosures/all_closures_skipped3772026/10/05 11:18:44 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50378=== CONT TestSetClientTLS/rejects_connection_without_client_cert379=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3802026/10/05 11:18:44 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=2000381--- PASS: TestFilterOversizedClosures (0.00s)382 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)383 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)384 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)385=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA386--- PASS: TestSetClientTLSErrors (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)388 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391=== CONT TestSetClientTLS/preserves_debug_logging_transport392--- PASS: TestDumpPathSingleFile (0.06s)393--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)394--- PASS: TestCaseHackSuffix (0.05s)395--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)3962026/10/05 11:18:44 http: TLS handshake error from 127.0.0.1:53485: remote error: tls: bad certificate397--- PASS: TestSetClientTLS (0.00s)398 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)399 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)400 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)401--- PASS: TestDumpPathMatchesNix (0.09s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld1".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-27053-1025767996/postgres1366136314/data ... ok417creating subdirectories ... ok418selecting dynamic shared memory implementation ... posix419selecting default "max_connections" ... 100420selecting default "shared_buffers" ... 128MB421selecting default time zone ... UTC422creating configuration files ... ok423running bootstrap script ... ok424performing post-bootstrap initialization ... ok425syncing data to disk ... ok426427initdb: warning: enabling "trust" authentication for local connections428initdb: 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.429430Success. You can now start the database server using:431432 pg_ctl -D /nix/var/nix/builds/nix-27053-1025767996/postgres1366136314/data -l logfile start4334342026-10-05 11:18:47.834 UTC [27419] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-05 11:18:47.835 UTC [27419] LOG: listening on Unix socket "/nix/var/nix/builds/nix-27053-1025767996/postgres1366136314/.s.PGSQL.5432"4362026-10-05 11:18:47.837 UTC [27427] LOG: database system was shut down at 2026-10-05 11:18:47 UTC4372026-10-05 11:18:47.838 UTC [27419] LOG: database system is ready to accept connections438/nix/var/nix/builds/nix-27053-1025767996/postgres1366136314:5432 - accepting connections439{"timestamp":"2026-10-05T11:18:50.06746Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"18866395-fede-4da2-b2b4-04505a98f028","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(2)"}440=== RUN TestService_AuthMiddleware441=== PAUSE TestService_AuthMiddleware442=== RUN TestService_AuthMiddleware_MTLSProxyHeader443=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader444=== RUN TestService_AuthMiddleware_MTLSBoundSubjects445=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects446=== RUN TestService_ReadAuthMiddleware447=== PAUSE TestService_ReadAuthMiddleware448=== RUN TestService_AuthMiddleware_OIDC449=== PAUSE TestService_AuthMiddleware_OIDC450=== RUN TestService_RequireScope_OIDC451=== PAUSE TestService_RequireScope_OIDC452=== RUN TestService_ReadScope_PublicByDefault453=== PAUSE TestService_ReadScope_PublicByDefault454=== RUN TestCacheConfigHandler455=== PAUSE TestCacheConfigHandler456=== RUN TestCacheStatsHandler457=== PAUSE TestCacheStatsHandler458=== RUN TestClientCADerivations459=== PAUSE TestClientCADerivations460=== RUN TestClientErrorHandling461=== PAUSE TestClientErrorHandling462=== RUN TestClientIntegration463=== PAUSE TestClientIntegration464=== RUN TestClientMultipleUploads465=== PAUSE TestClientMultipleUploads466=== RUN TestClientWithDependencies467=== PAUSE TestClientWithDependencies468=== RUN TestClientSharedPathCommittedMidPush469=== PAUSE TestClientSharedPathCommittedMidPush470=== RUN TestPinProtectsFromGC471=== PAUSE TestPinProtectsFromGC472=== RUN TestClientPushesUseOnePush473=== PAUSE TestClientPushesUseOnePush474=== RUN TestClientFallsBackToClosures475=== PAUSE TestClientFallsBackToClosures476=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock477=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== RUN TestResolveDBConnectionString479=== PAUSE TestResolveDBConnectionString480=== RUN TestConnectWaitsForAPeerMigration481=== PAUSE TestConnectWaitsForAPeerMigration482=== RUN TestLeadElectsOneAndHandsOver483=== PAUSE TestLeadElectsOneAndHandsOver484=== RUN TestLeadIncumbentWinsAfterRestart4852026/10/05 11:18:50 INFO lead: acquired remote=192.0.2.1:12344862026/10/05 11:18:51 INFO lead: released remote=192.0.2.1:12344872026/10/05 11:18:51 INFO lead: acquired remote=192.0.2.1:12344882026/10/05 11:18:52 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (2.07s)490=== RUN TestLeadIncumbentAnnouncesAtOnce491=== PAUSE TestLeadIncumbentAnnouncesAtOnce492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestLeadEndsWhenItsConnectionHangs4952026/10/05 11:18:52 INFO lead: acquired remote=192.0.2.1:12344962026-10-05 11:18:53.567 UTC [27622] FATAL: terminating connection due to administrator command4972026/10/05 11:18:53 INFO lead: acquired remote=192.0.2.1:12344982026/10/05 11:18:54 WARN lead: lock connection lost error="timeout: context deadline exceeded"4992026/10/05 11:18:54 INFO lead: released remote=192.0.2.1:12345002026/10/05 11:18:54 INFO lead: released remote=192.0.2.1:1234501--- PASS: TestLeadEndsWhenItsConnectionHangs (2.73s)502=== RUN TestGCAdvisoryLockBlocksConcurrentRun503=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun504=== RUN TestGCBugBareHashReferences505=== PAUSE TestGCBugBareHashReferences506=== RUN TestGCMetrics507=== PAUSE TestGCMetrics508=== RUN TestPushDedupSurvivesConcurrentGC509=== PAUSE TestPushDedupSurvivesConcurrentGC510=== RUN TestDeduplicatedObjectsRecordedAsPending511=== PAUSE TestDeduplicatedObjectsRecordedAsPending512=== RUN TestGCSweepSkipsPendingObjects513=== PAUSE TestGCSweepSkipsPendingObjects514=== RUN TestTombstonedObjectOfferedWithoutWaiting515=== PAUSE TestTombstonedObjectOfferedWithoutWaiting516=== RUN TestGCSweepDeliversEachKeyOnce517=== PAUSE TestGCSweepDeliversEachKeyOnce518=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== RUN TestForceGCDuringPushOffersSweptObject521=== PAUSE TestForceGCDuringPushOffersSweptObject522=== RUN TestFailedS3DeleteKeepsTombstone523=== PAUSE TestFailedS3DeleteKeepsTombstone524=== RUN TestSweepSkipsRowsLockedByPush525=== PAUSE TestSweepSkipsRowsLockedByPush526=== RUN TestRegisterCompletedObjectNeedsPendingRow527=== PAUSE TestRegisterCompletedObjectNeedsPendingRow528=== RUN TestGetExistingObjectsLocksRows529=== PAUSE TestGetExistingObjectsLocksRows530=== RUN TestSweepRechecksPendingAfterLocking531=== PAUSE TestSweepRechecksPendingAfterLocking532=== RUN TestPushWaitsForSweepHoldingRow533=== PAUSE TestPushWaitsForSweepHoldingRow534=== RUN TestCommitRacingPendingCleanupKeepsObjects535=== PAUSE TestCommitRacingPendingCleanupKeepsObjects536=== RUN TestGCEndsOnShutdown537=== PAUSE TestGCEndsOnShutdown538=== RUN TestGCTaskStore_StartNew539=== PAUSE TestGCTaskStore_StartNew540=== RUN TestGCTaskStore_DeduplicateSameParams541=== PAUSE TestGCTaskStore_DeduplicateSameParams542=== RUN TestGCTaskStore_ConflictDifferentParams543=== PAUSE TestGCTaskStore_ConflictDifferentParams544=== RUN TestGCTaskStore_GetEmpty545=== PAUSE TestGCTaskStore_GetEmpty546=== RUN TestGCTaskStore_GetReturnsLatest547=== PAUSE TestGCTaskStore_GetReturnsLatest548=== RUN TestGCTaskStore_CompletedAllowsNewTask549=== PAUSE TestGCTaskStore_CompletedAllowsNewTask550=== RUN TestGCTaskStore_PhaseUpdates551=== PAUSE TestGCTaskStore_PhaseUpdates552=== RUN TestGCTaskStore_Fail553=== PAUSE TestGCTaskStore_Fail554=== RUN TestGracefulShutdownDrainsInflight555=== PAUSE TestGracefulShutdownDrainsInflight556=== RUN TestService_healthCheckHandler557=== PAUSE TestService_healthCheckHandler558=== RUN TestService_readinessHandler559=== PAUSE TestService_readinessHandler560=== RUN TestGenerateLandingPage561=== PAUSE TestGenerateLandingPage562=== RUN TestCacheConfigHandlerMaxNarSize563=== PAUSE TestCacheConfigHandlerMaxNarSize564=== RUN TestCreatePendingClosureRejectsOversizedNAR565=== PAUSE TestCreatePendingClosureRejectsOversizedNAR566=== RUN TestNARDeduplicationMetadataUploadBug567=== PAUSE TestNARDeduplicationMetadataUploadBug568=== RUN TestMetricsInventory569=== PAUSE TestMetricsInventory570=== RUN TestService_NativeMTLS571=== PAUSE TestService_NativeMTLS572=== RUN TestServerTLSConfig573=== PAUSE TestServerTLSConfig574=== RUN TestMultipartCleanup575=== PAUSE TestMultipartCleanup576=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== RUN TestPendingCleanupUsesOneCutoff579=== PAUSE TestPendingCleanupUsesOneCutoff580=== RUN TestObjectStatsTrigger581=== PAUSE TestObjectStatsTrigger582=== RUN TestOrphanedObjectsGC583=== PAUSE TestOrphanedObjectsGC584=== RUN TestOrphanedObjectsGCStressTest585=== PAUSE TestOrphanedObjectsGCStressTest586=== RUN TestCreatePin_ReservedPins587=== PAUSE TestCreatePin_ReservedPins588=== RUN TestPresentReportsOnlyClosureRoots589=== PAUSE TestPresentReportsOnlyClosureRoots590=== RUN TestPresentNotReportedWhileGCDeletesClosure591=== PAUSE TestPresentNotReportedWhileGCDeletesClosure592=== RUN TestParseSingleRange593=== PAUSE TestParseSingleRange594=== RUN TestProxyHeadersOnlyTrustedOnSocket595=== PAUSE TestProxyHeadersOnlyTrustedOnSocket596=== RUN TestIsValidCachePath597=== PAUSE TestIsValidCachePath598=== RUN TestReadProxyNarinfo599=== PAUSE TestReadProxyNarinfo600=== RUN TestReadProxyNarinfoAlreadyDecompressed601=== PAUSE TestReadProxyNarinfoAlreadyDecompressed602=== RUN TestReadProxyNarStreaming603=== PAUSE TestReadProxyNarStreaming604=== RUN TestReadProxy404605=== PAUSE TestReadProxy404606=== RUN TestReadProxyInvalidPath607=== PAUSE TestReadProxyInvalidPath608=== RUN TestReadProxyHead609=== PAUSE TestReadProxyHead610=== RUN TestReadProxyOutlastsServerWriteTimeout611=== PAUSE TestReadProxyOutlastsServerWriteTimeout612=== RUN TestReadProxyConditionalGet613=== PAUSE TestReadProxyConditionalGet614=== RUN TestReadProxyRootRedirectsToIndexHTML615=== PAUSE TestReadProxyRootRedirectsToIndexHTML616=== RUN TestReadProxyDisabled617=== PAUSE TestReadProxyDisabled618=== RUN TestReadRedirectNar619=== PAUSE TestReadRedirectNar620=== RUN TestReadRedirectKeepsNarinfoProxied621=== PAUSE TestReadRedirectKeepsNarinfoProxied622=== RUN TestReadProxyRangeRequest623=== PAUSE TestReadProxyRangeRequest624=== RUN TestReadRedirectUsesPublicS3URL625=== PAUSE TestReadRedirectUsesPublicS3URL626=== RUN TestPush_OverlappingRootsStoreOneRowPerKey627=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey628=== RUN TestPush_CompleteCommitsEveryRoot629=== PAUSE TestPush_CompleteCommitsEveryRoot630=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit631=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit632=== RUN TestPush_RejectsBadRequests633=== PAUSE TestPush_RejectsBadRequests634=== RUN TestPush_SignsNarinfosOfItsPendingObjects635=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects636=== RUN TestRedundantMultipartUpload637=== PAUSE TestRedundantMultipartUpload638=== RUN TestCompleteMultipartUpload_ErrorButObjectExists639=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists640=== RUN TestCompletedNarNotReofferedAcrossClosures641=== PAUSE TestCompletedNarNotReofferedAcrossClosures642=== RUN TestPresignedUploadRegisteredBeforeCommit643=== PAUSE TestPresignedUploadRegisteredBeforeCommit644=== RUN TestService_Rustfstest645=== PAUSE TestService_Rustfstest646=== RUN TestParseSize647=== PAUSE TestParseSize648=== RUN TestSkippedUploadsHandler649=== PAUSE TestSkippedUploadsHandler650=== RUN TestSystemdListenerNotActivated651--- PASS: TestSystemdListenerNotActivated (0.00s)652=== RUN TestWatchdogBeatsWhenHealthy653--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)654=== RUN TestWatchdogSkipsWhenUnhealthy6552026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:18:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestPendingClosureWriteTimeout670=== PAUSE TestPendingClosureWriteTimeout671=== RUN TestIsValidUploadKey672=== PAUSE TestIsValidUploadKey673=== RUN TestUploadHandlersRejectInvalidKeys674=== PAUSE TestUploadHandlersRejectInvalidKeys675=== RUN TestUploadHandlersRejectOversizedBody676=== PAUSE TestUploadHandlersRejectOversizedBody677=== RUN TestService_cleanupPendingClosuresHandler678=== PAUSE TestService_cleanupPendingClosuresHandler679=== RUN TestService_createPendingClosureHandler680=== PAUSE TestService_createPendingClosureHandler681=== RUN TestService_verifyS3Integrity682=== PAUSE TestService_verifyS3Integrity683=== RUN TestCompleteMultipartUnregistered684=== PAUSE TestCompleteMultipartUnregistered685=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT686=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT687=== CONT TestParseSingleRange688=== CONT TestService_AuthMiddleware689=== CONT TestPush_RejectsBadRequests690=== RUN TestParseSingleRange/none691=== PAUSE TestParseSingleRange/none692=== RUN TestParseSingleRange/unknown_unit693=== PAUSE TestParseSingleRange/unknown_unit694=== RUN TestParseSingleRange/multi-range_ignored695=== CONT TestSweepSkipsRowsLockedByPush696=== PAUSE TestParseSingleRange/multi-range_ignored697=== RUN TestParseSingleRange/malformed_no_dash698=== PAUSE TestParseSingleRange/malformed_no_dash699=== RUN TestParseSingleRange/malformed_both_empty700=== PAUSE TestParseSingleRange/malformed_both_empty701=== RUN TestParseSingleRange/malformed_end_before_start702=== PAUSE TestParseSingleRange/malformed_end_before_start703=== RUN TestParseSingleRange/closed704=== PAUSE TestParseSingleRange/closed705=== RUN TestParseSingleRange/open-ended706=== CONT TestPresentNotReportedWhileGCDeletesClosure707=== CONT TestPresentReportsOnlyClosureRoots708=== CONT TestCreatePin_ReservedPins709=== CONT TestOrphanedObjectsGCStressTest710=== CONT TestOrphanedObjectsGC711=== CONT TestObjectStatsTrigger712=== PAUSE TestParseSingleRange/open-ended713=== RUN TestParseSingleRange/end_clamped_to_size714=== PAUSE TestParseSingleRange/end_clamped_to_size715=== RUN TestParseSingleRange/suffix716=== PAUSE TestParseSingleRange/suffix717=== RUN TestParseSingleRange/suffix_exceeds_size718=== PAUSE TestParseSingleRange/suffix_exceeds_size719=== RUN TestParseSingleRange/single_byte720=== PAUSE TestParseSingleRange/single_byte721=== RUN TestParseSingleRange/start_past_EOF722=== PAUSE TestParseSingleRange/start_past_EOF723=== RUN TestParseSingleRange/start_far_past_EOF724=== PAUSE TestParseSingleRange/start_far_past_EOF725=== CONT TestPendingCleanupUsesOneCutoff7262026/10/05 11:18:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53768/oidc7272026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures7282026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures7292026/10/05 11:18:55 INFO Received cleanup request method=DELETE path=/api/pending_closures7302026/10/05 11:18:56 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"731--- PASS: TestService_AuthMiddleware (0.83s)732=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded733=== NAME TestOrphanedObjectsGC734 orphaned_objects_gc_test.go:290: GC Test Summary:735 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A736 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B737 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)738 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)739 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects740--- PASS: TestOrphanedObjectsGC (1.05s)741=== CONT TestMultipartCleanup742--- PASS: TestPresentReportsOnlyClosureRoots (1.41s)743=== CONT TestServerTLSConfig744=== RUN TestServerTLSConfig/no_client_CA745=== PAUSE TestServerTLSConfig/no_client_CA746=== RUN TestServerTLSConfig/missing_CA_file747=== PAUSE TestServerTLSConfig/missing_CA_file748=== RUN TestServerTLSConfig/not_a_PEM_file749=== PAUSE TestServerTLSConfig/not_a_PEM_file750=== CONT TestService_NativeMTLS751--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.56s)752=== CONT TestMetricsInventory753=== RUN TestPush_RejectsBadRequests/no_objects754=== PAUSE TestPush_RejectsBadRequests/no_objects755=== RUN TestPush_RejectsBadRequests/bad_root756=== PAUSE TestPush_RejectsBadRequests/bad_root757=== RUN TestPush_RejectsBadRequests/root_not_in_objects758=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects759=== RUN TestPush_RejectsBadRequests/no_roots760=== PAUSE TestPush_RejectsBadRequests/no_roots761=== CONT TestNARDeduplicationMetadataUploadBug7622026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=07632026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period7642026/10/05 11:18:57 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=07652026/10/05 11:18:57 INFO Vacuumed table table=pending_closures7662026/10/05 11:18:57 INFO Vacuumed table table=pending_objects7672026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads7682026/10/05 11:18:57 INFO Vacuumed table table=closures7692026/10/05 11:18:57 INFO Vacuumed table table=objects7702026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=07712026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period7722026/10/05 11:18:57 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=07732026/10/05 11:18:57 INFO Vacuumed table table=pending_closures7742026/10/05 11:18:57 INFO Vacuumed table table=pending_objects7752026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads7762026/10/05 11:18:57 INFO Vacuumed table table=closures7772026/10/05 11:18:57 INFO Vacuumed table table=objects778--- PASS: TestSweepSkipsRowsLockedByPush (1.87s)779=== CONT TestCreatePendingClosureRejectsOversizedNAR7802026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures781--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)782=== CONT TestCacheConfigHandlerMaxNarSize783--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)784=== CONT TestGenerateLandingPage785--- PASS: TestGenerateLandingPage (0.00s)786=== CONT TestService_readinessHandler7872026/10/05 11:18:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7882026/10/05 11:18:57 WARN Refused reserved pin name=worker-x86_64-linux7892026/10/05 11:18:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7902026/10/05 11:18:57 INFO Received create pin request method=POST path=/api/pins/my-app7912026/10/05 11:18:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux792--- PASS: TestCreatePin_ReservedPins (2.02s)793=== CONT TestService_healthCheckHandler794--- PASS: TestObjectStatsTrigger (2.30s)795=== CONT TestGracefulShutdownDrainsInflight7962026/10/05 11:18:57 INFO Starting HTTP server address=127.0.0.1:537947972026/10/05 11:18:57 INFO Shutdown signal received, draining in-flight requests timeout=10s798--- PASS: TestGracefulShutdownDrainsInflight (0.07s)799=== CONT TestGCTaskStore_Fail800--- PASS: TestGCTaskStore_Fail (0.00s)801=== CONT TestGCTaskStore_PhaseUpdates802--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)803=== CONT TestGCTaskStore_CompletedAllowsNewTask804--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)805=== CONT TestGCTaskStore_GetReturnsLatest806--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)807=== CONT TestGCTaskStore_GetEmpty808--- PASS: TestGCTaskStore_GetEmpty (0.00s)809=== CONT TestGCTaskStore_ConflictDifferentParams810--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)811=== CONT TestGCTaskStore_DeduplicateSameParams812--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)813=== CONT TestGCTaskStore_StartNew814--- PASS: TestGCTaskStore_StartNew (0.00s)815=== CONT TestGCEndsOnShutdown816=== RUN TestGCEndsOnShutdown/before_the_run817=== PAUSE TestGCEndsOnShutdown/before_the_run818=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete819=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete820=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark821=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark822=== CONT TestCommitRacingPendingCleanupKeepsObjects8232026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures824--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.76s)825=== CONT TestPushWaitsForSweepHoldingRow8262026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures8272026/10/05 11:18:58 INFO Received cleanup request method=DELETE path=/api/pending_closures8282026/10/05 11:18:58 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8292026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=18302026/10/05 11:18:58 INFO Received cleanup request method=DELETE path=/api/pending_closures8312026/10/05 11:18:58 INFO Aborted multipart uploads count=1 kept=0832--- PASS: TestMultipartCleanup (1.90s)833=== CONT TestSweepRechecksPendingAfterLocking8342026/10/05 11:18:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8352026/10/05 11:18:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"836--- PASS: TestService_NativeMTLS (1.74s)837=== CONT TestGetExistingObjectsLocksRows838--- PASS: TestMetricsInventory (2.04s)839=== CONT TestRegisterCompletedObjectNeedsPendingRow840=== NAME TestNARDeduplicationMetadataUploadBug841 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-27053-1025767996/TestNARDeduplicationMetadataUploadBug1528084520/001/store/v70qhj6s9raaiddsraq9z25ix9yi762f-file1.txt8422026/10/05 11:18:59 INFO Received push request method=POST path=/api/pushes8432026/10/05 11:18:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8442026/10/05 11:18:59 INFO Uploading v70qhj6s9raaiddsraq9z25ix9yi762f-file1.txt (160B)8452026/10/05 11:18:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8462026/10/05 11:18:59 WARN Failed to register uploaded object key=v70qhj6s9raaiddsraq9z25ix9yi762f.ls error="server returned 404: 404 page not found\n"8472026/10/05 11:18:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8482026/10/05 11:18:59 INFO Signed narinfos id=1 count=18492026/10/05 11:18:59 INFO Uploading 1 narinfos8502026/10/05 11:18:59 INFO Received complete push request method=POST path=/api/pushes/1/complete8512026/10/05 11:18:59 WARN Failed to register uploaded object key=v70qhj6s9raaiddsraq9z25ix9yi762f.narinfo error="server returned 404: 404 page not found\n"8522026/10/05 11:18:59 INFO Upload complete. (136ms)853 metadata_upload_test.go:54: Retrieved narinfo from S3:854 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestNARDeduplicationMetadataUploadBug1528084520/001/store/v70qhj6s9raaiddsraq9z25ix9yi762f-file1.txt855 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst856 Compression: zstd857 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf858 NarSize: 160859 References: 860 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf861 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)862 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):863 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8642026/10/05 11:18:59 WARN readiness check failed error="closed pool"865--- PASS: TestService_readinessHandler (2.34s)866=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock867=== NAME TestNARDeduplicationMetadataUploadBug868 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-27053-1025767996/TestNARDeduplicationMetadataUploadBug1528084520/001/store/1446748m48n72cxp9v0l0z8w3dgmzvil-file2.txt8692026/10/05 11:18:59 INFO Received push request method=POST path=/api/pushes8702026/10/05 11:18:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8712026/10/05 11:18:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8722026/10/05 11:18:59 INFO Signed narinfos id=2 count=18732026/10/05 11:18:59 WARN Failed to register uploaded object key=1446748m48n72cxp9v0l0z8w3dgmzvil.ls error="server returned 404: 404 page not found\n"8742026/10/05 11:18:59 INFO Uploading 1 narinfos8752026/10/05 11:18:59 INFO Received complete push request method=POST path=/api/pushes/2/complete8762026/10/05 11:18:59 WARN Failed to register uploaded object key=1446748m48n72cxp9v0l0z8w3dgmzvil.narinfo error="server returned 404: 404 page not found\n"8772026/10/05 11:18:59 INFO Upload complete. (83ms)878 metadata_upload_test.go:76: Retrieved narinfo from S3:879 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestNARDeduplicationMetadataUploadBug1528084520/001/store/1446748m48n72cxp9v0l0z8w3dgmzvil-file2.txt880 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst881 Compression: zstd882 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf883 NarSize: 160884 References: 885 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf886 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)887 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):888 {"version":1,"root":{"type":"regular","size":44}}889--- PASS: TestNARDeduplicationMetadataUploadBug (2.85s)890=== CONT TestFailedS3DeleteKeepsTombstone891--- PASS: TestService_healthCheckHandler (2.44s)892=== CONT TestForceGCDuringPushOffersSweptObject893=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows894=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows895=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check896=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check897=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8982026/10/05 11:18:59 INFO Aborted multipart uploads count=0 kept=08992026/10/05 11:18:59 WARN Force mode enabled - objects will be deleted immediately without grace period9002026/10/05 11:18:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09012026/10/05 11:19:00 INFO Vacuumed table table=pending_closures9022026/10/05 11:19:00 INFO Vacuumed table table=pending_objects9032026/10/05 11:19:00 INFO Vacuumed table table=multipart_uploads9042026/10/05 11:19:00 INFO Vacuumed table table=closures9052026/10/05 11:19:00 INFO Vacuumed table table=objects906--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.51s)907=== CONT TestGCSweepDeliversEachKeyOnce9082026/10/05 11:19:00 INFO Received uploads request method=POST path=/api/pending_closures9092026/10/05 11:19:00 INFO Aborted multipart uploads count=0 kept=09102026/10/05 11:19:00 WARN Force mode enabled - objects will be deleted immediately without grace period9112026/10/05 11:19:00 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=09122026/10/05 11:19:00 INFO Vacuumed table table=pending_closures9132026/10/05 11:19:00 INFO Vacuumed table table=pending_objects9142026/10/05 11:19:00 INFO Vacuumed table table=multipart_uploads9152026/10/05 11:19:00 INFO Vacuumed table table=closures9162026/10/05 11:19:00 INFO Vacuumed table table=objects917--- PASS: TestSweepRechecksPendingAfterLocking (2.48s)918=== CONT TestTombstonedObjectOfferedWithoutWaiting919--- PASS: TestPushWaitsForSweepHoldingRow (2.88s)920=== CONT TestGCSweepSkipsPendingObjects921--- PASS: TestGetExistingObjectsLocksRows (2.33s)922=== CONT TestDeduplicatedObjectsRecordedAsPending923--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.13s)924=== CONT TestPushDedupSurvivesConcurrentGC925=== NAME TestOrphanedObjectsGCStressTest926 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains927 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion9282026/10/05 11:19:01 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/05 11:19:01 INFO Aborted multipart uploads count=0 kept=09302026/10/05 11:19:01 WARN Force mode enabled - objects will be deleted immediately without grace period9312026/10/05 11:19:01 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9322026/10/05 11:19:01 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."933--- PASS: TestFailedS3DeleteKeepsTombstone (2.20s)934=== CONT TestGCMetrics9352026/10/05 11:19:01 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/05 11:19:01 INFO Aborted multipart uploads count=1 kept=09372026/10/05 11:19:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9382026/10/05 11:19:01 INFO Aborted multipart uploads count=1 kept=0939--- PASS: TestPendingCleanupUsesOneCutoff (6.77s)940=== CONT TestGCBugBareHashReferences941--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.46s)942=== CONT TestGCAdvisoryLockBlocksConcurrentRun9432026/10/05 11:19:02 INFO Aborted multipart uploads count=0 kept=09442026/10/05 11:19:02 WARN Force mode enabled - objects will be deleted immediately without grace period9452026/10/05 11:19:02 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=09462026/10/05 11:19:02 INFO Vacuumed table table=pending_closures9472026/10/05 11:19:02 INFO Vacuumed table table=pending_objects9482026/10/05 11:19:02 INFO Vacuumed table table=multipart_uploads9492026/10/05 11:19:02 INFO Vacuumed table table=closures9502026/10/05 11:19:02 INFO Vacuumed table table=objects951--- PASS: TestGCSweepDeliversEachKeyOnce (2.21s)952=== CONT TestLeadEndsOnShutdown953--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.97s)954=== CONT TestLeadIncumbentAnnouncesAtOnce9552026/10/05 11:19:02 INFO Received uploads request method=POST path=/api/pending_closures956--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.77s)957=== CONT TestLeadElectsOneAndHandsOver9582026/10/05 11:19:02 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/05 11:19:02 INFO Aborted multipart uploads count=0 kept=09602026/10/05 11:19:02 WARN Force mode enabled - objects will be deleted immediately without grace period9612026/10/05 11:19:02 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=09622026/10/05 11:19:02 INFO Vacuumed table table=pending_closures9632026/10/05 11:19:02 INFO Vacuumed table table=pending_objects9642026/10/05 11:19:02 INFO Vacuumed table table=multipart_uploads9652026/10/05 11:19:02 INFO Vacuumed table table=closures9662026/10/05 11:19:02 INFO Vacuumed table table=objects967--- PASS: TestGCSweepSkipsPendingObjects (2.01s)968=== CONT TestConnectWaitsForAPeerMigration9692026/10/05 11:19:02 INFO Received uploads request method=POST path=/api/pending_closures970--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.19s)971=== CONT TestResolveDBConnectionString972=== RUN TestResolveDBConnectionString/flag_wins973=== PAUSE TestResolveDBConnectionString/flag_wins974=== RUN TestResolveDBConnectionString/file_when_flag_empty975=== PAUSE TestResolveDBConnectionString/file_when_flag_empty976=== RUN TestResolveDBConnectionString/missing_file_is_an_error977=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error978=== RUN TestResolveDBConnectionString/PGHOST_allows_empty979=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty980=== RUN TestResolveDBConnectionString/nothing_configured981=== PAUSE TestResolveDBConnectionString/nothing_configured982=== CONT TestClientCADerivations9832026/10/05 11:19:03 INFO Received uploads request method=POST path=/api/pending_closures9842026/10/05 11:19:03 INFO Aborted multipart uploads count=0 kept=09852026/10/05 11:19:03 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=09862026/10/05 11:19:03 INFO Vacuumed table table=pending_closures9872026/10/05 11:19:03 INFO Vacuumed table table=pending_objects9882026/10/05 11:19:03 INFO Vacuumed table table=multipart_uploads9892026/10/05 11:19:03 INFO Vacuumed table table=closures9902026/10/05 11:19:03 INFO Vacuumed table table=objects9912026/10/05 11:19:03 INFO Aborted multipart uploads count=0 kept=09922026/10/05 11:19:03 WARN Force mode enabled - objects will be deleted immediately without grace period9932026/10/05 11:19:03 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=09942026/10/05 11:19:03 INFO Vacuumed table table=pending_closures9952026/10/05 11:19:03 INFO Vacuumed table table=pending_objects9962026/10/05 11:19:03 INFO Vacuumed table table=multipart_uploads9972026/10/05 11:19:03 INFO Vacuumed table table=closures9982026/10/05 11:19:03 INFO Vacuumed table table=objects999--- PASS: TestPushDedupSurvivesConcurrentGC (2.33s)1000=== CONT TestClientFallsBackToClosures1001=== NAME TestOrphanedObjectsGCStressTest1002 orphaned_objects_gc_test.go:509: Stress test completed successfully:1003 orphaned_objects_gc_test.go:510: - Active objects preserved: 201004 orphaned_objects_gc_test.go:511: - Objects deleted: 2101005 orphaned_objects_gc_test.go:512: - Total GC'd: 2101006--- PASS: TestOrphanedObjectsGCStressTest (8.10s)1007=== CONT TestClientPushesUseOnePush10082026/10/05 11:19:03 INFO Aborted multipart uploads count=0 kept=010092026/10/05 11:19:03 WARN Force mode enabled - objects will be deleted immediately without grace period10102026/10/05 11:19:03 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=010112026/10/05 11:19:03 INFO Vacuumed table table=pending_closures10122026/10/05 11:19:03 INFO Vacuumed table table=pending_objects10132026/10/05 11:19:03 INFO Vacuumed table table=multipart_uploads10142026/10/05 11:19:03 INFO Vacuumed table table=closures10152026/10/05 11:19:03 INFO Vacuumed table table=objects1016--- PASS: TestGCMetrics (1.77s)1017=== CONT TestPinProtectsFromGC1018--- PASS: TestGCBugBareHashReferences (2.24s)1019=== CONT TestClientSharedPathCommittedMidPush10202026/10/05 11:19:04 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1021--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.19s)1022=== CONT TestClientWithDependencies10232026/10/05 11:19:04 INFO lead: acquired remote=192.0.2.1:123410242026/10/05 11:19:05 INFO lead: acquired remote=192.0.2.1:123410252026/10/05 11:19:05 INFO lead: released remote=192.0.2.1:12341026--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.61s)1027=== CONT TestClientMultipleUploads10282026/10/05 11:19:05 INFO lead: acquired remote=192.0.2.1:123410292026/10/05 11:19:05 INFO lead: released remote=192.0.2.1:12341030--- PASS: TestLeadEndsOnShutdown (3.41s)1031=== CONT TestClientIntegration1032{"timestamp":"2026-10-05T11:19:05.991711Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}1033=== NAME TestClientCADerivations1034 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-27053-1025767996/TestClientCADerivations853793224/001/store/cdaz2fwa1hc7v9wwy32xy0nqvbvvd613-ca-test1035 client_ca_test.go:139: Found 1 dependencies (including self)10362026/10/05 11:19:06 INFO Received push request method=POST path=/api/pushes10372026/10/05 11:19:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10382026/10/05 11:19:06 INFO Uploading cdaz2fwa1hc7v9wwy32xy0nqvbvvd613-ca-test (144B)10392026/10/05 11:19:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10402026/10/05 11:19:06 WARN Failed to register uploaded object key=cdaz2fwa1hc7v9wwy32xy0nqvbvvd613.ls error="server returned 404: 404 page not found\n"10412026/10/05 11:19:06 WARN Failed to register uploaded object key=log/28v9hk2zf04iznmlr669xcs94p6kmxr8-ca-test.drv error="server returned 404: 404 page not found\n"10422026/10/05 11:19:06 INFO lead: released remote=192.0.2.1:123410432026/10/05 11:19:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10442026/10/05 11:19:06 INFO Signed narinfos id=1 count=110452026/10/05 11:19:06 INFO Uploading 1 narinfos10462026/10/05 11:19:06 INFO Received complete push request method=POST path=/api/pushes/1/complete10472026/10/05 11:19:06 WARN Failed to register uploaded object key=cdaz2fwa1hc7v9wwy32xy0nqvbvvd613.narinfo error="server returned 404: 404 page not found\n"10482026/10/05 11:19:06 INFO Upload complete. (193ms)1049 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientCADerivations853793224/001/store/cdaz2fwa1hc7v9wwy32xy0nqvbvvd613-ca-test1050 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1051 Compression: zstd1052 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1053 NarSize: 1441054 References: 1055 Deriver: /nix/var/nix/builds/nix-27053-1025767996/TestClientCADerivations853793224/001/store/28v9hk2zf04iznmlr669xcs94p6kmxr8-ca-test.drv1056 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1057 client_ca_test.go:185: Checking for realisation files in S3...1058 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1059 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache10602026/10/05 11:19:06 INFO lead: acquired remote=192.0.2.1:123410612026/10/05 11:19:06 INFO Received uploads request method=POST path=/api/pending_closures1062 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket39?endpoint=http://localhost:53568®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-27053-1025767996/TestClientCADerivations853793224/001/store'1063 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 110642026/10/05 11:19:06 INFO Received uploads request method=POST path=/api/pending_closures10652026/10/05 11:19:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10662026/10/05 11:19:06 INFO Uploading 1kw8fj2z8lc44f64sfdjgcrmrydyhxrn-shared-dep (136B)10672026/10/05 11:19:06 INFO Uploading 1p9d8bzxc484hyjm8x81r1nz2x0k8xsy-b (248B)10682026/10/05 11:19:06 WARN Failed to register uploaded object key=gd1xyqmh6xwarnvn1iyfhmb5bdppdlv6.ls error="server returned 404: 404 page not found\n"10692026/10/05 11:19:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10702026/10/05 11:19:06 WARN Failed to register uploaded object key=1kw8fj2z8lc44f64sfdjgcrmrydyhxrn.ls error="server returned 404: 404 page not found\n"10712026/10/05 11:19:06 WARN Failed to register uploaded object key=1p9d8bzxc484hyjm8x81r1nz2x0k8xsy.ls error="server returned 404: 404 page not found\n"10722026/10/05 11:19:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10732026/10/05 11:19:06 WARN Failed to register uploaded object key=nar/0xi3r1ysrhg3c9mbr81665rn4rw0zn5zcmc8asdhpgdp177ln3bl.nar.zst error="server returned 404: 404 page not found\n"10742026/10/05 11:19:06 INFO Signed narinfos id=1 count=210752026/10/05 11:19:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10762026/10/05 11:19:06 INFO Signed narinfos id=2 count=210772026/10/05 11:19:06 INFO Uploading 4 narinfos10782026/10/05 11:19:06 WARN Failed to register uploaded object key=1kw8fj2z8lc44f64sfdjgcrmrydyhxrn.narinfo error="server returned 404: 404 page not found\n"10792026/10/05 11:19:06 WARN Failed to register uploaded object key=gd1xyqmh6xwarnvn1iyfhmb5bdppdlv6.narinfo error="server returned 404: 404 page not found\n"10802026/10/05 11:19:06 WARN Failed to register uploaded object key=1p9d8bzxc484hyjm8x81r1nz2x0k8xsy.narinfo error="server returned 404: 404 page not found\n"1081--- PASS: TestClientCADerivations (3.99s)1082=== CONT TestClientErrorHandling1083=== RUN TestClientErrorHandling/InvalidStorePath1084=== PAUSE TestClientErrorHandling/InvalidStorePath1085=== RUN TestClientErrorHandling/InvalidAuthToken1086=== PAUSE TestClientErrorHandling/InvalidAuthToken1087=== RUN TestClientErrorHandling/ServerNotAvailable1088=== PAUSE TestClientErrorHandling/ServerNotAvailable1089=== CONT TestService_cleanupPendingClosuresHandler10902026/10/05 11:19:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10912026/10/05 11:19:06 WARN Failed to register uploaded object key=1kw8fj2z8lc44f64sfdjgcrmrydyhxrn.narinfo error="server returned 404: 404 page not found\n"10922026/10/05 11:19:06 INFO Completed upload id=110932026/10/05 11:19:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10942026/10/05 11:19:06 INFO Completed upload id=210952026/10/05 11:19:06 INFO Upload complete. (188ms)1096=== NAME TestClientFallsBackToClosures1097 client_pushes_test.go:112: Retrieved narinfo from S3:1098 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientFallsBackToClosures2642005726/001/store/1kw8fj2z8lc44f64sfdjgcrmrydyhxrn-shared-dep1099 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1100 Compression: zstd1101 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821102 NarSize: 1361103 References: 1104 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1105 client_pushes_test.go:112: Retrieved narinfo from S3:1106 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientFallsBackToClosures2642005726/001/store/gd1xyqmh6xwarnvn1iyfhmb5bdppdlv6-a1107 URL: nar/0xi3r1ysrhg3c9mbr81665rn4rw0zn5zcmc8asdhpgdp177ln3bl.nar.zst1108 Compression: zstd1109 NarHash: sha256:0xi3r1ysrhg3c9mbr81665rn4rw0zn5zcmc8asdhpgdp177ln3bl1110 NarSize: 2481111 References: /nix/var/nix/builds/nix-27053-1025767996/TestClientFallsBackToClosures2642005726/001/store/1kw8fj2z8lc44f64sfdjgcrmrydyhxrn-shared-dep1112 CA: text:sha256:0wdbw640pnx1zqzc21dbq54xba3mczifjm4a0xp8649qb81690lm1113 client_pushes_test.go:112: Retrieved narinfo from S3:1114 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientFallsBackToClosures2642005726/001/store/1p9d8bzxc484hyjm8x81r1nz2x0k8xsy-b1115 URL: nar/0xi3r1ysrhg3c9mbr81665rn4rw0zn5zcmc8asdhpgdp177ln3bl.nar.zst1116 Compression: zstd1117 NarHash: sha256:0xi3r1ysrhg3c9mbr81665rn4rw0zn5zcmc8asdhpgdp177ln3bl1118 NarSize: 2481119 References: /nix/var/nix/builds/nix-27053-1025767996/TestClientFallsBackToClosures2642005726/001/store/1kw8fj2z8lc44f64sfdjgcrmrydyhxrn-shared-dep1120 CA: text:sha256:0wdbw640pnx1zqzc21dbq54xba3mczifjm4a0xp8649qb81690lm1121--- PASS: TestClientFallsBackToClosures (3.67s)1122=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11232026/10/05 11:19:07 INFO Received push request method=POST path=/api/pushes11242026/10/05 11:19:07 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11252026/10/05 11:19:07 INFO Uploading zwvc9xv24v0plmlvv1ynxcrbi2ihfi41-shared-dep (136B)11262026/10/05 11:19:07 INFO Uploading vnlg9nhqy676g7d8dzd1042d8xykfa4n-a (248B)11272026/10/05 11:19:07 WARN Failed to register uploaded object key=vnlg9nhqy676g7d8dzd1042d8xykfa4n.ls error="server returned 404: 404 page not found\n"11282026/10/05 11:19:07 WARN Failed to register uploaded object key=lfch8whgwvvbkx69smarq16cb9sschzg.ls error="server returned 404: 404 page not found\n"11292026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11302026/10/05 11:19:07 WARN Failed to register uploaded object key=zwvc9xv24v0plmlvv1ynxcrbi2ihfi41.ls error="server returned 404: 404 page not found\n"11312026/10/05 11:19:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11322026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/1nw4hx86f2nq95w0qr5idk3i1qkq12r1ya383cxhj7rm7bv1pdhn.nar.zst error="server returned 404: 404 page not found\n"11332026/10/05 11:19:07 INFO Signed narinfos id=1 count=311342026/10/05 11:19:07 INFO Uploading 3 narinfos1135=== NAME TestPinProtectsFromGC1136 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-27053-1025767996/TestPinProtectsFromGC590323608/001/store/ghrn16f83rr5cq56xbslxgqfm0dq811w-pinned-file.txt1137 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-27053-1025767996/TestPinProtectsFromGC590323608/001/store/iday38bzsdwp55gnzd691b6yzyma4yyj-unpinned-file.txt11382026/10/05 11:19:07 WARN Failed to register uploaded object key=vnlg9nhqy676g7d8dzd1042d8xykfa4n.narinfo error="server returned 404: 404 page not found\n"11392026/10/05 11:19:07 WARN Failed to register uploaded object key=zwvc9xv24v0plmlvv1ynxcrbi2ihfi41.narinfo error="server returned 404: 404 page not found\n"11402026/10/05 11:19:07 INFO Received complete push request method=POST path=/api/pushes/1/complete11412026/10/05 11:19:07 WARN Failed to register uploaded object key=lfch8whgwvvbkx69smarq16cb9sschzg.narinfo error="server returned 404: 404 page not found\n"11422026/10/05 11:19:07 INFO Upload complete. (154ms)1143=== NAME TestClientPushesUseOnePush1144 client_pushes_test.go:97: Retrieved narinfo from S3:1145 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientPushesUseOnePush553861945/001/store/zwvc9xv24v0plmlvv1ynxcrbi2ihfi41-shared-dep1146 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1147 Compression: zstd1148 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821149 NarSize: 1361150 References: 1151 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1152 client_pushes_test.go:97: Retrieved narinfo from S3:1153 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientPushesUseOnePush553861945/001/store/vnlg9nhqy676g7d8dzd1042d8xykfa4n-a1154 URL: nar/1nw4hx86f2nq95w0qr5idk3i1qkq12r1ya383cxhj7rm7bv1pdhn.nar.zst1155 Compression: zstd1156 NarHash: sha256:1nw4hx86f2nq95w0qr5idk3i1qkq12r1ya383cxhj7rm7bv1pdhn1157 NarSize: 2481158 References: /nix/var/nix/builds/nix-27053-1025767996/TestClientPushesUseOnePush553861945/001/store/zwvc9xv24v0plmlvv1ynxcrbi2ihfi41-shared-dep1159 CA: text:sha256:0xmlnk5qsip2dk1fjp03dydgy2ihr2vaas453206a633db4q65py1160 client_pushes_test.go:97: Retrieved narinfo from S3:1161 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientPushesUseOnePush553861945/001/store/lfch8whgwvvbkx69smarq16cb9sschzg-b1162 URL: nar/1nw4hx86f2nq95w0qr5idk3i1qkq12r1ya383cxhj7rm7bv1pdhn.nar.zst1163 Compression: zstd1164 NarHash: sha256:1nw4hx86f2nq95w0qr5idk3i1qkq12r1ya383cxhj7rm7bv1pdhn1165 NarSize: 2481166 References: /nix/var/nix/builds/nix-27053-1025767996/TestClientPushesUseOnePush553861945/001/store/zwvc9xv24v0plmlvv1ynxcrbi2ihfi41-shared-dep1167 CA: text:sha256:0xmlnk5qsip2dk1fjp03dydgy2ihr2vaas453206a633db4q65py11682026/10/05 11:19:07 INFO Received push request method=POST path=/api/pushes11692026/10/05 11:19:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11702026/10/05 11:19:07 INFO Uploading ghrn16f83rr5cq56xbslxgqfm0dq811w-pinned-file.txt (128B)1171--- PASS: TestClientPushesUseOnePush (3.97s)1172=== CONT TestCompleteMultipartUnregistered11732026/10/05 11:19:07 WARN Failed to register uploaded object key=ghrn16f83rr5cq56xbslxgqfm0dq811w.ls error="server returned 404: 404 page not found\n"11742026/10/05 11:19:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11752026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11762026/10/05 11:19:07 INFO Signed narinfos id=1 count=111772026/10/05 11:19:07 INFO Uploading 1 narinfos11782026/10/05 11:19:07 INFO Received complete push request method=POST path=/api/pushes/1/complete11792026/10/05 11:19:07 WARN Failed to register uploaded object key=ghrn16f83rr5cq56xbslxgqfm0dq811w.narinfo error="server returned 404: 404 page not found\n"11802026/10/05 11:19:07 INFO Upload complete. (152ms)11812026/10/05 11:19:07 INFO Received push request method=POST path=/api/pushes11822026/10/05 11:19:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11832026/10/05 11:19:07 INFO Uploading iday38bzsdwp55gnzd691b6yzyma4yyj-unpinned-file.txt (128B)11842026/10/05 11:19:07 WARN Failed to register uploaded object key=iday38bzsdwp55gnzd691b6yzyma4yyj.ls error="server returned 404: 404 page not found\n"11852026/10/05 11:19:07 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11862026/10/05 11:19:07 INFO Signed narinfos id=2 count=111872026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11882026/10/05 11:19:07 INFO Uploading 1 narinfos11892026/10/05 11:19:07 INFO Received complete push request method=POST path=/api/pushes/2/complete11902026/10/05 11:19:07 WARN Failed to register uploaded object key=iday38bzsdwp55gnzd691b6yzyma4yyj.narinfo error="server returned 404: 404 page not found\n"11912026/10/05 11:19:07 INFO Upload complete. (96ms)11922026/10/05 11:19:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures11932026/10/05 11:19:07 INFO Garbage collection started11942026/10/05 11:19:07 INFO Aborted multipart uploads count=0 kept=011952026/10/05 11:19:07 WARN Force mode enabled - objects will be deleted immediately without grace period11962026/10/05 11:19:07 INFO Received push request method=POST path=/api/pushes11972026/10/05 11:19:07 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=011982026/10/05 11:19:07 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11992026/10/05 11:19:07 INFO Uploading xivvq9ls6q18ac3rhr502kmhml6hzfqx-shared-dep (136B)12002026/10/05 11:19:07 INFO Uploading n764mzjnws7rbbbj4likxsq3hl5x4y0p-top (256B)12012026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/1kv9y489hk5rs14vz6ggcdqqzvri17ccb578d3h1zxbkp15vnkhf.nar.zst error="server returned 404: 404 page not found\n"12022026/10/05 11:19:07 WARN Failed to register uploaded object key=xivvq9ls6q18ac3rhr502kmhml6hzfqx.ls error="server returned 404: 404 page not found\n"12032026/10/05 11:19:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12042026/10/05 11:19:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12052026/10/05 11:19:07 WARN Failed to register uploaded object key=n764mzjnws7rbbbj4likxsq3hl5x4y0p.ls error="server returned 404: 404 page not found\n"12062026/10/05 11:19:07 INFO Signed narinfos id=1 count=212072026/10/05 11:19:07 INFO Uploading 2 narinfos12082026/10/05 11:19:07 INFO Vacuumed table table=pending_closures12092026/10/05 11:19:07 WARN Failed to register uploaded object key=n764mzjnws7rbbbj4likxsq3hl5x4y0p.narinfo error="server returned 404: 404 page not found\n"12102026/10/05 11:19:07 INFO Received complete push request method=POST path=/api/pushes/1/complete12112026/10/05 11:19:07 WARN Failed to register uploaded object key=xivvq9ls6q18ac3rhr502kmhml6hzfqx.narinfo error="server returned 404: 404 page not found\n"12122026/10/05 11:19:07 INFO Vacuumed table table=pending_objects12132026/10/05 11:19:07 INFO Vacuumed table table=multipart_uploads12142026/10/05 11:19:07 INFO Upload complete. (144ms)1215=== NAME TestClientSharedPathCommittedMidPush1216 client_integration_test.go:680: Retrieved narinfo from S3:1217 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientSharedPathCommittedMidPush3589977522/001/store/xivvq9ls6q18ac3rhr502kmhml6hzfqx-shared-dep1218 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1219 Compression: zstd1220 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821221 NarSize: 1361222 References: 1223 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1224 client_integration_test.go:680: Retrieved narinfo from S3:1225 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientSharedPathCommittedMidPush3589977522/001/store/n764mzjnws7rbbbj4likxsq3hl5x4y0p-top1226 URL: nar/1kv9y489hk5rs14vz6ggcdqqzvri17ccb578d3h1zxbkp15vnkhf.nar.zst1227 Compression: zstd1228 NarHash: sha256:1kv9y489hk5rs14vz6ggcdqqzvri17ccb578d3h1zxbkp15vnkhf1229 NarSize: 2561230 References: /nix/var/nix/builds/nix-27053-1025767996/TestClientSharedPathCommittedMidPush3589977522/001/store/xivvq9ls6q18ac3rhr502kmhml6hzfqx-shared-dep1231 CA: text:sha256:1qg906n5gvd1cv90m73hmjq79dhgg79qiawxhxx2a182izy8dkn712322026/10/05 11:19:07 INFO Vacuumed table table=closures12332026/10/05 11:19:07 INFO lead: released remote=192.0.2.1:12341234--- PASS: TestLeadElectsOneAndHandsOver (5.21s)1235=== CONT TestService_verifyS3Integrity12362026/10/05 11:19:07 INFO Vacuumed table table=objects1237--- PASS: TestClientSharedPathCommittedMidPush (3.46s)1238=== CONT TestService_createPendingClosureHandler1239=== NAME TestClientWithDependencies1240 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-27053-1025767996/TestClientWithDependencies501384861/001/store/vak45f9kmz8xr51f4f908w9a3zwng788-test-script1241=== NAME TestClientMultipleUploads1242 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-27053-1025767996/TestClientMultipleUploads4009484315/001/store/gqzqzkz27nknc9sk7dcp1l4ihy4c4haw-test-file-0.txt1243=== NAME TestClientWithDependencies1244 client_integration_test.go:615: Found 1 dependencies (including self)1245=== NAME TestClientMultipleUploads1246 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-27053-1025767996/TestClientMultipleUploads4009484315/001/store/09jpvg67lbd6nclql2wjjl8il643fnl6-test-file-1.txt12472026/10/05 11:19:07 INFO Received push request method=POST path=/api/pushes12482026/10/05 11:19:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/10/05 11:19:08 INFO Uploading vak45f9kmz8xr51f4f908w9a3zwng788-test-script (136B)12502026/10/05 11:19:08 WARN Failed to register uploaded object key=vak45f9kmz8xr51f4f908w9a3zwng788.ls error="server returned 404: 404 page not found\n"12512026/10/05 11:19:08 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1252 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-27053-1025767996/TestClientMultipleUploads4009484315/001/store/py43msq3japhyb3shh9f7cf8xmsml9y9-test-file-2.txt12532026/10/05 11:19:08 WARN Failed to register uploaded object key=log/13iwanvna6abvc5ndf7g2qh4r279j4fg-test-script.drv error="server returned 404: 404 page not found\n"12542026/10/05 11:19:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12552026/10/05 11:19:08 INFO Signed narinfos id=1 count=112562026/10/05 11:19:08 INFO Uploading 1 narinfos12572026/10/05 11:19:08 INFO Received complete push request method=POST path=/api/pushes/1/complete12582026/10/05 11:19:08 WARN Failed to register uploaded object key=vak45f9kmz8xr51f4f908w9a3zwng788.narinfo error="server returned 404: 404 page not found\n"12592026/10/05 11:19:08 INFO Upload complete. (166ms)1260=== NAME TestClientWithDependencies1261 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-27053-1025767996/TestClientWithDependencies501384861/001/store) requires matching store prefix1262=== NAME TestClientIntegration1263 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-27053-1025767996/TestClientIntegration2484288004/002/store/c0dfxkrhpy30s3sk273d23svlzp05nml-test-file.txt12642026/10/05 11:19:08 INFO Received push request method=POST path=/api/pushes1265--- PASS: TestClientWithDependencies (3.85s)1266=== CONT TestUploadHandlersRejectInvalidKeys1267=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1268=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1269=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1270=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1271=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1272=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1273=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1274=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1275=== CONT TestUploadHandlersRejectOversizedBody12762026/10/05 11:19:08 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12772026/10/05 11:19:08 INFO Uploading 09jpvg67lbd6nclql2wjjl8il643fnl6-test-file-1.txt (160B)12782026/10/05 11:19:08 INFO Uploading gqzqzkz27nknc9sk7dcp1l4ihy4c4haw-test-file-0.txt (160B)12792026/10/05 11:19:08 INFO Uploading py43msq3japhyb3shh9f7cf8xmsml9y9-test-file-2.txt (160B)1280=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1281=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1282=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1283=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1284=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1285=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1286=== CONT TestProxyWriteTimeout1287=== RUN TestProxyWriteTimeout/narinfo1288=== PAUSE TestProxyWriteTimeout/narinfo1289=== RUN TestProxyWriteTimeout/1_GiB_nar1290=== PAUSE TestProxyWriteTimeout/1_GiB_nar1291=== RUN TestProxyWriteTimeout/10_GiB_nar1292=== PAUSE TestProxyWriteTimeout/10_GiB_nar1293=== RUN TestProxyWriteTimeout/unknown_size1294=== PAUSE TestProxyWriteTimeout/unknown_size1295=== CONT TestIsValidUploadKey1296=== RUN TestIsValidUploadKey/narinfo1297=== PAUSE TestIsValidUploadKey/narinfo1298=== RUN TestIsValidUploadKey/nar_zst1299=== PAUSE TestIsValidUploadKey/nar_zst1300=== RUN TestIsValidUploadKey/nar_xz1301=== PAUSE TestIsValidUploadKey/nar_xz1302=== RUN TestIsValidUploadKey/nar_plain1303=== PAUSE TestIsValidUploadKey/nar_plain1304=== RUN TestIsValidUploadKey/listing1305=== PAUSE TestIsValidUploadKey/listing1306=== RUN TestIsValidUploadKey/build_log1307=== PAUSE TestIsValidUploadKey/build_log1308=== RUN TestIsValidUploadKey/build_log_home-manager_file1309=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1310=== RUN TestIsValidUploadKey/build_log_plus_in_name1311=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1312=== RUN TestIsValidUploadKey/build_log_question_mark1313=== PAUSE TestIsValidUploadKey/build_log_question_mark1314=== RUN TestIsValidUploadKey/build_log_equals1315=== PAUSE TestIsValidUploadKey/build_log_equals1316=== RUN TestIsValidUploadKey/realisation1317=== PAUSE TestIsValidUploadKey/realisation1318=== RUN TestIsValidUploadKey/realisation_plus_in_output1319=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1320=== RUN TestIsValidUploadKey/nix-cache-info1321=== PAUSE TestIsValidUploadKey/nix-cache-info1322=== RUN TestIsValidUploadKey/index.html1323=== PAUSE TestIsValidUploadKey/index.html1324=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1325=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1326=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1327=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1328=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1329=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1330=== RUN TestIsValidUploadKey/traversal1331=== PAUSE TestIsValidUploadKey/traversal1332=== RUN TestIsValidUploadKey/traversal_nar1333=== PAUSE TestIsValidUploadKey/traversal_nar1334=== RUN TestIsValidUploadKey/absolute1335=== PAUSE TestIsValidUploadKey/absolute1336=== RUN TestIsValidUploadKey/empty_key1337=== PAUSE TestIsValidUploadKey/empty_key1338=== RUN TestIsValidUploadKey/unknown_type1339=== PAUSE TestIsValidUploadKey/unknown_type1340=== CONT TestPendingClosureWriteTimeout1341=== RUN TestPendingClosureWriteTimeout/empty1342=== PAUSE TestPendingClosureWriteTimeout/empty1343=== RUN TestPendingClosureWriteTimeout/400_objects1344=== PAUSE TestPendingClosureWriteTimeout/400_objects1345=== RUN TestPendingClosureWriteTimeout/670k_objects1346=== PAUSE TestPendingClosureWriteTimeout/670k_objects1347=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1348=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1349=== CONT TestService_ReadAuthMiddleware13502026/10/05 11:19:08 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13512026/10/05 11:19:08 WARN Failed to register uploaded object key=09jpvg67lbd6nclql2wjjl8il643fnl6.ls error="server returned 404: 404 page not found\n"13522026/10/05 11:19:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13532026/10/05 11:19:08 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13542026/10/05 11:19:08 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13552026/10/05 11:19:08 WARN Failed to register uploaded object key=gqzqzkz27nknc9sk7dcp1l4ihy4c4haw.ls error="server returned 404: 404 page not found\n"13562026/10/05 11:19:08 WARN Failed to register uploaded object key=py43msq3japhyb3shh9f7cf8xmsml9y9.ls error="server returned 404: 404 page not found\n"13572026/10/05 11:19:08 INFO Signed narinfos id=1 count=313582026/10/05 11:19:08 INFO Uploading 3 narinfos13592026/10/05 11:19:08 INFO Received complete push request method=POST path=/api/pushes/1/complete13602026/10/05 11:19:08 WARN Failed to register uploaded object key=py43msq3japhyb3shh9f7cf8xmsml9y9.narinfo error="server returned 404: 404 page not found\n"13612026/10/05 11:19:08 WARN Failed to register uploaded object key=09jpvg67lbd6nclql2wjjl8il643fnl6.narinfo error="server returned 404: 404 page not found\n"13622026/10/05 11:19:08 WARN Failed to register uploaded object key=gqzqzkz27nknc9sk7dcp1l4ihy4c4haw.narinfo error="server returned 404: 404 page not found\n"13632026/10/05 11:19:08 INFO Upload complete. (152ms)1364=== NAME TestClientMultipleUploads1365 client_integration_test.go:369: Uploaded 3 paths in 191.193583ms13662026/10/05 11:19:08 INFO Received push request method=POST path=/api/pushes13672026/10/05 11:19:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13682026/10/05 11:19:08 INFO Uploading c0dfxkrhpy30s3sk273d23svlzp05nml-test-file.txt (152B)13692026/10/05 11:19:08 WARN Failed to register uploaded object key=c0dfxkrhpy30s3sk273d23svlzp05nml.ls error="server returned 404: 404 page not found\n"13702026/10/05 11:19:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13712026/10/05 11:19:08 INFO Signed narinfos id=1 count=113722026/10/05 11:19:08 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13732026/10/05 11:19:08 INFO Uploading 1 narinfos1374--- PASS: TestClientMultipleUploads (3.30s)1375=== CONT TestService_RequireScope_OIDC13762026/10/05 11:19:08 INFO Received complete push request method=POST path=/api/pushes/1/complete13772026/10/05 11:19:08 WARN Failed to register uploaded object key=c0dfxkrhpy30s3sk273d23svlzp05nml.narinfo error="server returned 404: 404 page not found\n"13782026/10/05 11:19:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53984/oidc13792026/10/05 11:19:08 INFO Upload complete. (175ms)13802026/10/05 11:19:08 INFO All 1 paths already cached1381=== NAME TestClientIntegration1382 client_integration_test.go:312: Retrieved narinfo from S3:1383 StorePath: /nix/var/nix/builds/nix-27053-1025767996/TestClientIntegration2484288004/002/store/c0dfxkrhpy30s3sk273d23svlzp05nml-test-file.txt1384 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1385 Compression: zstd1386 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11387 NarSize: 1521388 References: 1389 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11390 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1391 client_integration_test.go:313: Decompressed .ls content (64 bytes):1392 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1393 client_integration_test.go:316: Testing garbage collection...13942026/10/05 11:19:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures13952026/10/05 11:19:08 INFO Garbage collection started13962026/10/05 11:19:08 INFO Aborted multipart uploads count=0 kept=013972026/10/05 11:19:08 WARN Force mode enabled - objects will be deleted immediately without grace period13982026/10/05 11:19:08 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=013992026/10/05 11:19:08 INFO Vacuumed table table=pending_closures14002026/10/05 11:19:08 INFO Vacuumed table table=pending_objects14012026/10/05 11:19:08 INFO Vacuumed table table=multipart_uploads14022026/10/05 11:19:08 INFO Vacuumed table table=closures14032026/10/05 11:19:08 INFO Vacuumed table table=objects14042026/10/05 11:19:08 INFO Received cleanup request method=DELETE path=/api/pending_closures14052026/10/05 11:19:08 INFO Aborted multipart uploads count=0 kept=014062026/10/05 11:19:08 INFO Received uploads request method=POST path=/api/pending_closures14072026/10/05 11:19:09 INFO Received cleanup request method=DELETE path=/api/pending_closures14082026/10/05 11:19:09 INFO Aborted multipart uploads count=1 kept=014092026/10/05 11:19:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14102026-10-05 11:19:09.055 UTC [27943] ERROR: Closure does not exist: id=114112026-10-05 11:19:09.055 UTC [27943] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE14122026-10-05 11:19:09.055 UTC [27943] STATEMENT: -- name: CommitPendingClosure :exec1413 SELECT commit_pending_closure($1::bigint)1414 1415--- PASS: TestService_cleanupPendingClosuresHandler (2.23s)1416=== CONT TestService_AuthMiddleware_OIDC14172026/10/05 11:19:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53992/oidc14182026/10/05 11:19:09 INFO Received uploads request method=POST path=/api/pending_closures1419--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.40s)1420=== CONT TestCacheStatsHandler14212026/10/05 11:19:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=014222026/10/05 11:19:09 INFO Received create pin request method=POST path=/api/pins/myapp14232026/10/05 11:19:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14242026/10/05 11:19:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1425--- PASS: TestCompleteMultipartUnregistered (2.23s)1426=== CONT TestCacheConfigHandler1427=== RUN TestCacheConfigHandler/full_config,_no_issuer1428=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1429=== RUN TestCacheConfigHandler/no_cache_url_configured1430=== PAUSE TestCacheConfigHandler/no_cache_url_configured1431=== RUN TestCacheConfigHandler/no_signing_keys1432=== PAUSE TestCacheConfigHandler/no_signing_keys1433=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1434=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1435=== CONT TestService_ReadScope_PublicByDefault14362026/10/05 11:19:09 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-27053-1025767996/TestPinProtectsFromGC590323608/001/store/ghrn16f83rr5cq56xbslxgqfm0dq811w-pinned-file.txt narinfo_key=ghrn16f83rr5cq56xbslxgqfm0dq811w.narinfo14372026/10/05 11:19:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures14382026/10/05 11:19:09 INFO Garbage collection started14392026/10/05 11:19:09 INFO Aborted multipart uploads count=0 kept=014402026/10/05 11:19:09 WARN Force mode enabled - objects will be deleted immediately without grace period14412026/10/05 11:19:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014422026/10/05 11:19:09 INFO Vacuumed table table=pending_closures14432026/10/05 11:19:09 INFO Vacuumed table table=pending_objects14442026/10/05 11:19:09 INFO Vacuumed table table=multipart_uploads14452026/10/05 11:19:09 INFO Vacuumed table table=closures14462026/10/05 11:19:09 INFO Vacuumed table table=objects14472026/10/05 11:19:09 INFO Received uploads request method=POST path=/api/pending_closures1448--- PASS: TestConnectWaitsForAPeerMigration (7.55s)1449=== CONT TestPresignedUploadRegisteredBeforeCommit14502026/10/05 11:19:10 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/05 11:19:10 INFO Received uploads request method=POST path=/api/pending_closures14522026/10/05 11:19:10 INFO Received uploads request method=POST path=/api/pending_closures14532026/10/05 11:19:10 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01454=== NAME TestClientIntegration1455 client_integration_test.go:323: Objects in database after GC:1456 client_integration_test.go:323: Successfully deleted all objects with GC --force1457{"timestamp":"2026-10-05T11:19:10.425089Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}1458--- PASS: TestClientIntegration (4.77s)1459=== CONT TestSkippedUploadsHandler14602026/10/05 11:19:10 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001461--- PASS: TestSkippedUploadsHandler (0.00s)1462=== CONT TestParseSize1463--- PASS: TestParseSize (0.00s)1464=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1465--- PASS: TestService_ReadAuthMiddleware (2.41s)1466=== CONT TestService_Rustfstest1467=== RUN TestService_RequireScope_OIDC/builder_may_write1468=== PAUSE TestService_RequireScope_OIDC/builder_may_write1469=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1470=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1471=== RUN TestService_RequireScope_OIDC/ops_may_admin1472=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1473=== RUN TestService_RequireScope_OIDC/ops_may_not_write1474=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1475=== RUN TestService_RequireScope_OIDC/reader_may_not_write1476=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1477=== RUN TestService_RequireScope_OIDC/static_token_may_admin1478=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1479=== RUN TestService_RequireScope_OIDC/static_token_may_write1480=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1481=== RUN TestService_RequireScope_OIDC/reader_may_read1482=== PAUSE TestService_RequireScope_OIDC/reader_may_read1483=== RUN TestService_RequireScope_OIDC/writer_implies_read1484=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1485=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1486=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1487=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1488=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1489=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1490=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1491=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1492=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1493=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1494=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1495=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1496=== NAME TestPinProtectsFromGC1497 client_integration_test.go:840: Pin successfully protected closure from garbage collection14982026/10/05 11:19:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1499--- PASS: TestPinProtectsFromGC (8.07s)1500=== CONT TestCompletedNarNotReofferedAcrossClosures15012026/10/05 11:19:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmU5NjdkODM3LWI4YWEtNDM2MS1hNmNhLTkxZjZjNTY0NTVkMXgxNzkxMTk5MTQ5OTgyMTcyMDAw parts=1015022026/10/05 11:19:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15032026/10/05 11:19:11 INFO Completed upload id=115042026/10/05 11:19:11 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/05 11:19:11 INFO Received uploads request method=POST path=/api/pending_closures15062026/10/05 11:19:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15072026/10/05 11:19:11 WARN Found objects in DB but missing from S3, will re-upload count=11508--- PASS: TestService_verifyS3Integrity (4.03s)1509=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15102026/10/05 11:19:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15112026/10/05 11:19:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LjQ1ZDM0Zjg0LTQ5MDYtNDMyNi1iNzZiLTcxMjM5MmQ1NGQzN3gxNzkxMTk5MTUwMzExNTM2MDAw parts=1015122026/10/05 11:19:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15132026/10/05 11:19:11 INFO Completed upload id=115142026/10/05 11:19:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015152026/10/05 11:19:11 INFO Received uploads request method=POST path=/api/pending_closures15162026/10/05 11:19:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures15172026/10/05 11:19:12 INFO Aborted multipart uploads count=0 kept=015182026/10/05 11:19:12 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=015192026/10/05 11:19:12 INFO Vacuumed table table=pending_closures1520--- PASS: TestCacheStatsHandler (2.75s)1521=== CONT TestService_AuthMiddleware_MTLSProxyHeader15222026/10/05 11:19:12 INFO Vacuumed table table=pending_objects15232026/10/05 11:19:12 INFO Vacuumed table table=multipart_uploads15242026/10/05 11:19:12 INFO Vacuumed table table=closures15252026/10/05 11:19:12 INFO Vacuumed table table=objects15262026/10/05 11:19:12 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001527--- PASS: TestService_createPendingClosureHandler (4.47s)1528=== CONT TestRedundantMultipartUpload1529=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1530=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1531=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1532=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1533=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1534=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1535=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1536=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1537=== CONT TestReadProxyNarStreaming1538--- PASS: TestService_ReadScope_PublicByDefault (3.06s)1539=== CONT TestReadProxyConditionalGet15402026/10/05 11:19:13 INFO Received uploads request method=POST path=/api/pending_closures15412026/10/05 11:19:13 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15422026/10/05 11:19:13 INFO Received uploads request method=POST path=/api/pending_closures1543--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.01s)1544=== CONT TestReadProxyOutlastsServerWriteTimeout15452026/10/05 11:19:13 INFO Received uploads request method=POST path=/api/pending_closures1546--- PASS: TestService_Rustfstest (3.30s)1547=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15482026/10/05 11:19:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15492026/10/05 11:19:14 INFO Received uploads request method=POST path=/api/pending_closures15502026/10/05 11:19:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15512026/10/05 11:19:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmZlODI1NjJlLTlhN2UtNDBiNS1hMTY3LWYyYWE5ZTU5MDJiOHgxNzkxMTk5MTU0MzIwMDMyMDAw15522026/10/05 11:19:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmZlODI1NjJlLTlhN2UtNDBiNS1hMTY3LWYyYWE5ZTU5MDJiOHgxNzkxMTk5MTU0MzIwMDMyMDAw parts=11553--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.69s)1554=== CONT TestReadProxyHead15552026/10/05 11:19:14 INFO Received uploads request method=POST path=/api/pending_closures15562026/10/05 11:19:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15572026/10/05 11:19:15 WARN mTLS auth: bound subjects configured but subject DN unavailable15582026/10/05 11:19:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1559--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.51s)1560=== CONT TestPush_CompleteCommitsEveryRoot1561--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.40s)1562=== CONT TestReadProxyInvalidPath15632026/10/05 11:19:15 INFO Received uploads request method=POST path=/api/pending_closures15642026/10/05 11:19:15 INFO Received uploads request method=POST path=/api/pending_closures1565--- PASS: TestReadProxyNarStreaming (3.82s)1566=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1567--- PASS: TestReadProxyConditionalGet (3.81s)1568=== CONT TestReadProxy40415692026/10/05 11:19:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15702026/10/05 11:19:16 WARN Rate limiter enabled after throttle name=s3-test rate=515712026/10/05 11:19:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1572=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1573 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101574 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001575--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.34s)1576=== CONT TestReadRedirectUsesPublicS3URL15772026/10/05 11:19:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3Ljk1MTg5MzdmLWFhOWItNGE2NS05MzM3LWFlN2YxZDhkNTFmOXgxNzkxMTk5MTU0OTYzMDQ0MDAw parts=1215782026/10/05 11:19:16 INFO Received uploads request method=POST path=/api/pending_closures1579--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.18s)1580=== CONT TestReadRedirectNar15812026/10/05 11:19:16 INFO Received push request method=POST path=/api/pushes15822026/10/05 11:19:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15832026/10/05 11:19:17 INFO Received push request method=POST path=/api/pushes15842026/10/05 11:19:17 INFO Aborted multipart uploads count=0 kept=015852026/10/05 11:19:17 WARN Force mode enabled - objects will be deleted immediately without grace period15862026/10/05 11:19:17 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=015872026/10/05 11:19:17 INFO Vacuumed table table=pending_closures15882026/10/05 11:19:17 INFO Vacuumed table table=pending_objects15892026/10/05 11:19:17 INFO Vacuumed table table=multipart_uploads15902026/10/05 11:19:17 INFO Vacuumed table table=closures15912026/10/05 11:19:17 INFO Vacuumed table table=objects15922026/10/05 11:19:17 INFO Received complete push request method=POST path=/api/pushes/2/complete1593--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.53s)1594=== CONT TestReadProxyDisabled1595--- PASS: TestReadProxyHead (2.85s)1596=== CONT TestReadProxyRangeRequest15972026/10/05 11:19:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15982026/10/05 11:19:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmI4NGJkNjcxLWQ0ZmEtNDc3ZS1hZTRhLTkzMWIzMTI1NDhiOXgxNzkxMTk5MTU1Nzg0MzQxMDAw parts=1215992026/10/05 11:19:17 INFO Received uploads request method=POST path=/api/pending_closures16002026/10/05 11:19:17 INFO Received uploads request method=POST path=/api/pending_closures16012026/10/05 11:19:17 INFO Received push request method=POST path=/api/pushes16022026/10/05 11:19:17 INFO Received complete push request method=POST path=/api/pushes/1/complete1603--- PASS: TestPush_CompleteCommitsEveryRoot (2.76s)1604=== CONT TestReadProxyRootRedirectsToIndexHTML1605--- PASS: TestReadProxyInvalidPath (2.67s)1606=== CONT TestReadRedirectKeepsNarinfoProxied16072026/10/05 11:19:18 INFO Received push request method=POST path=/api/pushes1608--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.83s)1609=== CONT TestPush_SignsNarinfosOfItsPendingObjects1610--- PASS: TestReadProxy404 (2.89s)1611=== CONT TestIsValidCachePath1612=== RUN TestIsValidCachePath/narinfo1613=== PAUSE TestIsValidCachePath/narinfo1614=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1615=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1616=== RUN TestIsValidCachePath/nar_zst1617=== PAUSE TestIsValidCachePath/nar_zst1618=== RUN TestIsValidCachePath/nar_xz1619=== PAUSE TestIsValidCachePath/nar_xz1620=== RUN TestIsValidCachePath/nar_bz21621=== PAUSE TestIsValidCachePath/nar_bz21622=== RUN TestIsValidCachePath/nar_uncompressed1623=== PAUSE TestIsValidCachePath/nar_uncompressed1624=== RUN TestIsValidCachePath/ls1625=== PAUSE TestIsValidCachePath/ls1626=== RUN TestIsValidCachePath/log1627=== PAUSE TestIsValidCachePath/log1628=== RUN TestIsValidCachePath/realisation1629=== PAUSE TestIsValidCachePath/realisation1630=== RUN TestIsValidCachePath/nix-cache-info1631=== PAUSE TestIsValidCachePath/nix-cache-info1632=== RUN TestIsValidCachePath/index.html1633=== PAUSE TestIsValidCachePath/index.html1634=== RUN TestIsValidCachePath/traversal_parent1635=== PAUSE TestIsValidCachePath/traversal_parent1636=== RUN TestIsValidCachePath/traversal_in_middle1637=== PAUSE TestIsValidCachePath/traversal_in_middle1638=== RUN TestIsValidCachePath/invalid_char_e1639=== PAUSE TestIsValidCachePath/invalid_char_e1640=== RUN TestIsValidCachePath/invalid_char_u1641=== PAUSE TestIsValidCachePath/invalid_char_u1642=== RUN TestIsValidCachePath/random_path1643=== PAUSE TestIsValidCachePath/random_path1644=== RUN TestIsValidCachePath/empty1645=== PAUSE TestIsValidCachePath/empty1646=== RUN TestIsValidCachePath/leading_slash1647=== PAUSE TestIsValidCachePath/leading_slash1648=== RUN TestIsValidCachePath/wrong_extension1649=== PAUSE TestIsValidCachePath/wrong_extension1650=== RUN TestIsValidCachePath/short_hash1651=== PAUSE TestIsValidCachePath/short_hash1652=== CONT TestProxyHeadersOnlyTrustedOnSocket16532026/10/05 11:19:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16542026/10/05 11:19:19 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmZiNmFiZGFhLTRiY2ItNDcxNi04ZGZmLTlmYzFmOWY3ZmMyYngxNzkxMTk5MTU3NzAwODM0MDAw error="Get \"http://127.0.0.1:1/bucket64/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"16552026/10/05 11:19:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Yjk4ZGQ2OGMtZjNlNi00NTlmLWIzNjctYjMwN2I3YmVhZTQ3LmI5NzBhMGZhLWFjZWEtNGE5ZS1hNDM4LTFhZDRlMGE1ZDNkZXgxNzkxMTk5MTU3NjYzNDUwMDAw parts=1216562026/10/05 11:19:19 INFO Received cleanup request method=DELETE path=/api/pending_closures16572026/10/05 11:19:19 INFO Aborted multipart uploads count=1 kept=01658--- PASS: TestRedundantMultipartUpload (7.36s)1659=== CONT TestReadProxyNarinfoAlreadyDecompressed1660--- PASS: TestReadRedirectNar (2.73s)1661=== CONT TestReadProxyNarinfo1662--- PASS: TestReadRedirectUsesPublicS3URL (3.04s)1663=== CONT TestParseSingleRange/none1664=== CONT TestParseSingleRange/start_far_past_EOF1665=== CONT TestParseSingleRange/start_past_EOF1666=== CONT TestParseSingleRange/single_byte1667=== CONT TestParseSingleRange/suffix_exceeds_size1668=== CONT TestParseSingleRange/suffix1669=== CONT TestParseSingleRange/end_clamped_to_size1670=== CONT TestParseSingleRange/open-ended1671=== CONT TestParseSingleRange/closed1672=== CONT TestParseSingleRange/malformed_end_before_start1673=== CONT TestParseSingleRange/malformed_both_empty1674=== CONT TestParseSingleRange/malformed_no_dash1675=== CONT TestParseSingleRange/multi-range_ignored1676=== CONT TestParseSingleRange/unknown_unit1677--- PASS: TestParseSingleRange (0.01s)1678 --- PASS: TestParseSingleRange/none (0.00s)1679 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1680 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1681 --- PASS: TestParseSingleRange/single_byte (0.00s)1682 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1683 --- PASS: TestParseSingleRange/suffix (0.00s)1684 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1685 --- PASS: TestParseSingleRange/open-ended (0.00s)1686 --- PASS: TestParseSingleRange/closed (0.00s)1687 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1688 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1689 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1690 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1691 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1692=== CONT TestServerTLSConfig/no_client_CA1693=== CONT TestServerTLSConfig/not_a_PEM_file1694=== CONT TestServerTLSConfig/missing_CA_file1695--- PASS: TestServerTLSConfig (0.00s)1696 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1697 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1698 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1699=== CONT TestPush_RejectsBadRequests/no_objects17002026/10/05 11:19:19 INFO Received push request method=POST path=/api/pushes1701=== CONT TestPush_RejectsBadRequests/root_not_in_objects17022026/10/05 11:19:19 INFO Received push request method=POST path=/api/pushes1703=== CONT TestPush_RejectsBadRequests/no_roots17042026/10/05 11:19:19 INFO Received push request method=POST path=/api/pushes1705=== CONT TestPush_RejectsBadRequests/bad_root17062026/10/05 11:19:19 INFO Received push request method=POST path=/api/pushes1707=== CONT TestGCEndsOnShutdown/before_the_run1708--- PASS: TestPush_RejectsBadRequests (1.57s)1709 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1710 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1711 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1712 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1713{"timestamp":"2026-10-05T11:19:20.059987Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}1714--- PASS: TestReadProxyRangeRequest (2.75s)1715=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1716--- PASS: TestReadProxyDisabled (3.11s)1717=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1718--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.92s)1719=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1720--- PASS: TestReadProxyOutlastsServerWriteTimeout (7.69s)1721=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1722--- PASS: TestReadRedirectKeepsNarinfoProxied (3.08s)1723=== CONT TestResolveDBConnectionString/flag_wins1724=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1725=== CONT TestResolveDBConnectionString/nothing_configured1726=== CONT TestResolveDBConnectionString/missing_file_is_an_error1727=== CONT TestResolveDBConnectionString/file_when_flag_empty1728=== CONT TestClientErrorHandling/InvalidStorePath1729--- PASS: TestResolveDBConnectionString (0.02s)1730 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1731 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1732 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1733 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1734 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17352026/10/05 11:19:21 INFO Received push request method=POST path=/api/pushes17362026/10/05 11:19:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17372026/10/05 11:19:21 INFO Signed narinfos id=1 count=11738--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.94s)1739=== CONT TestClientErrorHandling/InvalidAuthToken17402026/10/05 11:19:22 INFO Starting HTTP server address=127.0.0.1:5412517412026/10/05 11:19:22 INFO Starting HTTP server address=/nix/var/nix/builds/nix-27053-1025767996/TestProxyHeadersOnlyTrustedOnSocket271009203/001/proxy.sock17422026/10/05 11:19:22 WARN mTLS auth: subject not in bound subjects subject="CN=someone"17432026/10/05 11:19:22 INFO Shutdown signal received, draining in-flight requests timeout=10s1744--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.90s)1745=== CONT TestClientErrorHandling/ServerNotAvailable1746--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.96s)1747=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17482026/10/05 11:19:22 INFO Received uploads request method=POST path=/1749=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17502026/10/05 11:19:22 INFO Received complete multipart upload request method=POST path=/1751=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17522026/10/05 11:19:22 INFO Received request for more parts method=POST path=/1753=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17542026/10/05 11:19:22 INFO Received uploads request method=POST path=/1755--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1756 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1760=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17612026/10/05 11:19:22 INFO Received uploads request method=POST path=/17622026/10/05 11:19:22 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/present17632026/10/05 11:19:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.358902ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17642026/10/05 11:19:22 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1765=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17662026/10/05 11:19:22 INFO Received request for more parts method=POST path=/1767=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17682026/10/05 11:19:22 INFO Received complete multipart upload request method=POST path=/1769--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1770 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1771 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1772 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1773=== CONT TestProxyWriteTimeout/narinfo1774=== CONT TestProxyWriteTimeout/10_GiB_nar1775=== CONT TestProxyWriteTimeout/unknown_size1776=== CONT TestProxyWriteTimeout/1_GiB_nar1777--- PASS: TestProxyWriteTimeout (0.00s)1778 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1779 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1780 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1781 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1782=== CONT TestIsValidUploadKey/narinfo1783=== CONT TestIsValidUploadKey/realisation_plus_in_output1784=== CONT TestIsValidUploadKey/unknown_type1785=== CONT TestIsValidUploadKey/empty_key1786=== CONT TestIsValidUploadKey/absolute1787=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1788=== CONT TestIsValidUploadKey/traversal_nar1789=== CONT TestIsValidUploadKey/traversal1790=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1791=== CONT TestIsValidUploadKey/build_log_home-manager_file1792=== CONT TestIsValidUploadKey/realisation1793=== CONT TestIsValidUploadKey/build_log_equals1794=== CONT TestIsValidUploadKey/build_log_question_mark1795=== CONT TestIsValidUploadKey/build_log_plus_in_name1796=== CONT TestIsValidUploadKey/index.html1797=== CONT TestIsValidUploadKey/nix-cache-info1798=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1799=== CONT TestIsValidUploadKey/nar_plain1800=== CONT TestIsValidUploadKey/nar_xz1801=== CONT TestIsValidUploadKey/build_log1802=== CONT TestIsValidUploadKey/listing1803=== CONT TestIsValidUploadKey/nar_zst1804--- PASS: TestIsValidUploadKey (0.00s)1805 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1806 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1807 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1808 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1809 --- PASS: TestIsValidUploadKey/absolute (0.00s)1810 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1811 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1812 --- PASS: TestIsValidUploadKey/traversal (0.00s)1813 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1814 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1815 --- PASS: TestIsValidUploadKey/realisation (0.00s)1816 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1817 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1818 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1819 --- PASS: TestIsValidUploadKey/index.html (0.00s)1820 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1821 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1822 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1823 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1824 --- PASS: TestIsValidUploadKey/build_log (0.00s)1825 --- PASS: TestIsValidUploadKey/listing (0.00s)1826 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1827=== CONT TestPendingClosureWriteTimeout/empty1828=== CONT TestPendingClosureWriteTimeout/670k_objects1829=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18302026/10/05 11:19:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.926935ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1831=== CONT TestPendingClosureWriteTimeout/400_objects1832=== CONT TestCacheConfigHandler/full_config,_no_issuer1833=== CONT TestCacheConfigHandler/no_signing_keys1834=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1835=== CONT TestCacheConfigHandler/no_cache_url_configured1836--- PASS: TestCacheConfigHandler (0.00s)1837 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1838 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1839 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1840 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1841=== CONT TestService_RequireScope_OIDC/builder_may_write1842=== CONT TestService_RequireScope_OIDC/reader_may_read1843=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1844=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18452026/10/05 11:19:23 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]1846=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1847=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1848=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1849=== CONT TestService_RequireScope_OIDC/writer_implies_read1850=== CONT TestService_RequireScope_OIDC/reader_may_not_write1851=== CONT TestService_RequireScope_OIDC/static_token_may_write1852=== CONT TestService_RequireScope_OIDC/static_token_may_admin1853=== CONT TestService_RequireScope_OIDC/ops_may_admin1854=== CONT TestService_RequireScope_OIDC/ops_may_not_write1855=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1856=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1857=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18582026/10/05 11:19:23 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]1859=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1860=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18612026/10/05 11:19:23 WARN Authentication failed token_preview=eyJhbGciOi...y7vRkfZ5Vg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1862=== CONT TestIsValidCachePath/narinfo1863=== CONT TestIsValidCachePath/index.html1864=== CONT TestIsValidCachePath/nix-cache-info1865=== CONT TestIsValidCachePath/realisation1866=== CONT TestIsValidCachePath/log1867=== CONT TestIsValidCachePath/ls1868=== CONT TestIsValidCachePath/nar_uncompressed1869=== CONT TestIsValidCachePath/nar_bz21870=== CONT TestIsValidCachePath/nar_xz1871=== CONT TestIsValidCachePath/nar_zst1872=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1873=== CONT TestIsValidCachePath/empty1874=== CONT TestIsValidCachePath/wrong_extension1875=== CONT TestIsValidCachePath/short_hash1876=== CONT TestIsValidCachePath/leading_slash1877=== CONT TestIsValidCachePath/invalid_char_u1878=== CONT TestIsValidCachePath/random_path1879=== CONT TestIsValidCachePath/invalid_char_e1880=== CONT TestIsValidCachePath/traversal_in_middle1881=== CONT TestIsValidCachePath/traversal_parent1882--- PASS: TestIsValidCachePath (0.00s)1883 --- PASS: TestIsValidCachePath/narinfo (0.00s)1884 --- PASS: TestIsValidCachePath/index.html (0.00s)1885 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1886 --- PASS: TestIsValidCachePath/realisation (0.00s)1887 --- PASS: TestIsValidCachePath/log (0.00s)1888 --- PASS: TestIsValidCachePath/ls (0.00s)1889 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1890 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1891 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1892 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1893 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1894 --- PASS: TestIsValidCachePath/empty (0.00s)1895 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1896 --- PASS: TestIsValidCachePath/short_hash (0.00s)1897 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1898 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1899 --- PASS: TestIsValidCachePath/random_path (0.00s)1900 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1901 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1902 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1903--- PASS: TestService_RequireScope_OIDC (2.67s)1904 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1918--- PASS: TestService_AuthMiddleware_OIDC (3.21s)1919 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1920 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1921 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1922 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19232026/10/05 11:19:23 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161924--- PASS: TestReadProxyNarinfo (3.56s)19252026/10/05 11:19:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.021846ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19262026/10/05 11:19:23 INFO Aborted multipart uploads count=0 kept=019272026/10/05 11:19:23 WARN Force mode enabled - objects will be deleted immediately without grace period19282026-10-05 11:19:23.542 UTC [28072] ERROR: canceling statement due to user request19292026-10-05 11:19:23.542 UTC [28072] STATEMENT: -- name: MarkStaleObjects :execrows1930 WITH RECURSIVE ct AS (1931 SELECT timezone('UTC', now()) AS now1932 ),1933 closure_reach AS (1934 -- Start with all closure keys1935 SELECT o.key, o.refs1936 FROM objects o1937 INNER JOIN closures c ON o.key = c.key1938 UNION1939 -- Recursively add all referenced objects1940 SELECT o.key, o.refs1941 FROM objects o1942 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1943 ),1944 reachable_objects AS (1945 SELECT DISTINCT key FROM closure_reach1946 ),1947 stale_objects AS (1948 SELECT o.key1949 FROM objects AS o, ct1950 WHERE1951 NOT EXISTS (1952 SELECT 11953 FROM reachable_objects ro1954 WHERE ro.key = o.key1955 )1956 AND NOT EXISTS (1957 SELECT 11958 FROM pending_objects AS po1959 WHERE po.key = o.key1960 )1961 AND o.deleted_at IS NULL -- Only mark fresh objects1962 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1963 FOR UPDATE1964 )1965 UPDATE objects1966 SET1967 deleted_at = ct.now,1968 first_deleted_at = COALESCE(first_deleted_at, ct.now)1969 FROM stale_objects, ct1970 WHERE objects.key = stale_objects.key1971 19722026/10/05 11:19:23 INFO Aborted multipart uploads count=0 kept=019732026/10/05 11:19:23 WARN Force mode enabled - objects will be deleted immediately without grace period19742026/10/05 11:19:23 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53568/bucket86/?delete=\": context canceled"1975--- PASS: TestGCEndsOnShutdown (0.00s)1976 --- PASS: TestGCEndsOnShutdown/before_the_run (3.22s)1977 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.30s)1978 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.38s)19792026/10/05 11:19:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.479425966s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19802026/10/05 11:19:24 INFO Received uploads request method=POST path=/api/pending_closures19812026/10/05 11:19:24 INFO Aborted multipart uploads count=0 kept=019822026/10/05 11:19:24 WARN Force mode enabled - objects will be deleted immediately without grace period19832026/10/05 11:19:24 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=019842026/10/05 11:19:24 INFO Vacuumed table table=pending_closures19852026/10/05 11:19:24 INFO Vacuumed table table=pending_objects19862026/10/05 11:19:24 INFO Vacuumed table table=multipart_uploads19872026/10/05 11:19:24 INFO Vacuumed table table=closures19882026/10/05 11:19:24 INFO Vacuumed table table=objects19892026/10/05 11:19:24 INFO Received uploads request method=POST path=/api/pending_closures19902026/10/05 11:19:24 INFO Aborted multipart uploads count=0 kept=019912026/10/05 11:19:24 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/10/05 11:19:24 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=019932026/10/05 11:19:24 INFO Vacuumed table table=pending_closures19942026/10/05 11:19:24 INFO Vacuumed table table=pending_objects19952026/10/05 11:19:24 INFO Vacuumed table table=multipart_uploads19962026/10/05 11:19:24 INFO Vacuumed table table=closures19972026/10/05 11:19:24 INFO Vacuumed table table=objects1998--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1999 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.58s)2000 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.75s)20012026/10/05 11:19:25 INFO Received uploads request method=POST path=/api/pending_closures20022026/10/05 11:19:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20032026/10/05 11:19:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20042026/10/05 11:19: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-config20052026/10/05 11:19:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.484485ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20062026/10/05 11:19:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=397.979875ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2007--- PASS: TestPendingClosureWriteTimeout (0.00s)2008 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2009 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2010 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2011 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.18s)20122026/10/05 11:19:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.231289ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/05 11:19:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.633213253s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2014{"timestamp":"2026-10-05T11:19:27.371646Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}20152026/10/05 11:19:28 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"20162026/10/05 11:19:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20172026/10/05 11:19:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.6697ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20182026/10/05 11:19:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.221756ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20192026/10/05 11:19:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.637567ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/05 11:19:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.497331848s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20212026/10/05 11:19:31 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_closures20222026/10/05 11:19:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.385424ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20232026/10/05 11:19:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.304142ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20242026/10/05 11:19:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.397997ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2025{"timestamp":"2026-10-05T11:19:33.144359Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}20262026/10/05 11:19:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.739511197s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2027--- PASS: TestClientErrorHandling (0.00s)2028 --- PASS: TestClientErrorHandling/InvalidStorePath (3.60s)2029 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.39s)2030 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.82s)2031PASS2032{"timestamp":"2026-10-05T11:19:34.987402Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54016","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(11)"}20332026-10-05 11:19:35.127 UTC [27419] LOG: received smart shutdown request20342026-10-05 11:19:35.128 UTC [27419] LOG: background worker "logical replication launcher" (PID 27430) exited with exit code 120352026-10-05 11:19:35.135 UTC [27425] LOG: shutting down20362026-10-05 11:19:35.135 UTC [27425] LOG: checkpoint starting: shutdown immediate20372026-10-05 11:19:36.426 UTC [27425] LOG: checkpoint complete: wrote 12776 buffers (78.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.724 s, sync=0.527 s, total=1.291 s; sync files=31000, longest=0.001 s, average=0.001 s; distance=435696 kB, estimate=435696 kB; lsn=0/1C109288, redo lsn=0/1C10928820382026-10-05 11:19:36.432 UTC [27419] LOG: database system is shut down2039Running OIDC tests...2040=== RUN TestAudienceForIssuer2041=== PAUSE TestAudienceForIssuer2042=== RUN TestGlobMatch2043=== PAUSE TestGlobMatch2044=== RUN TestValidateToken_ValidToken2045=== PAUSE TestValidateToken_ValidToken2046=== RUN TestValidateToken_WrongAudience2047=== PAUSE TestValidateToken_WrongAudience2048=== RUN TestValidateToken_Expired2049=== PAUSE TestValidateToken_Expired2050=== RUN TestValidateToken_BoundClaimsMismatch2051=== PAUSE TestValidateToken_BoundClaimsMismatch2052=== RUN TestValidateToken_BoundSubjectMismatch2053=== PAUSE TestValidateToken_BoundSubjectMismatch2054=== RUN TestValidateToken_MultipleProviders2055=== PAUSE TestValidateToken_MultipleProviders2056=== RUN TestValidateToken_NoMatchingProvider2057=== PAUSE TestValidateToken_NoMatchingProvider2058=== RUN TestValidateToken_KubernetesServiceAccount2059=== PAUSE TestValidateToken_KubernetesServiceAccount2060=== RUN TestNewValidator_KubernetesRequiresCA2061=== PAUSE TestNewValidator_KubernetesRequiresCA2062=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2063=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2064=== RUN TestPins_ReservedForMatchingRule2065=== PAUSE TestPins_ReservedForMatchingRule2066=== RUN TestPins_TopLevelShorthand2067=== PAUSE TestPins_TopLevelShorthand2068=== RUN TestPins_ConfigValidation2069=== PAUSE TestPins_ConfigValidation2070=== RUN TestScopes_LegacyProviderDefaultsToWrite2071=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2072=== RUN TestScopes_Rules2073=== PAUSE TestScopes_Rules2074=== RUN TestScopes_ConfigValidation2075=== PAUSE TestScopes_ConfigValidation2076=== CONT TestAudienceForIssuer2077--- PASS: TestAudienceForIssuer (0.00s)2078=== CONT TestValidateToken_Expired2079=== CONT TestValidateToken_BoundClaimsMismatch2080=== CONT TestValidateToken_KubernetesServiceAccount2081=== CONT TestValidateToken_ValidToken2082=== CONT TestPins_ConfigValidation2083=== CONT TestPins_ReservedForMatchingRule2084=== CONT TestScopes_Rules2085=== CONT TestValidateToken_MultipleProviders2086=== CONT TestGlobMatch2087=== RUN TestGlobMatch/foo_foo2088=== PAUSE TestGlobMatch/foo_foo2089=== RUN TestGlobMatch/foo_bar2090=== PAUSE TestGlobMatch/foo_bar2091=== RUN TestGlobMatch/*_2092=== PAUSE TestGlobMatch/*_2093=== RUN TestGlobMatch/*_anything2094=== PAUSE TestGlobMatch/*_anything2095=== RUN TestGlobMatch/foo*_foo2096=== PAUSE TestGlobMatch/foo*_foo2097=== RUN TestGlobMatch/foo*_foobar2098=== PAUSE TestGlobMatch/foo*_foobar2099=== RUN TestGlobMatch/foo*_bar2100=== PAUSE TestGlobMatch/foo*_bar2101=== RUN TestGlobMatch/*bar_bar2102=== PAUSE TestGlobMatch/*bar_bar2103=== RUN TestGlobMatch/*bar_foobar2104=== PAUSE TestGlobMatch/*bar_foobar2105=== RUN TestGlobMatch/*bar_foo2106=== PAUSE TestGlobMatch/*bar_foo2107=== RUN TestGlobMatch/foo*bar_foobar2108=== PAUSE TestGlobMatch/foo*bar_foobar2109=== RUN TestGlobMatch/foo*bar_foo123bar2110=== PAUSE TestGlobMatch/foo*bar_foo123bar2111=== RUN TestGlobMatch/foo*bar_foobarbaz2112=== PAUSE TestGlobMatch/foo*bar_foobarbaz2113=== RUN TestGlobMatch/*/*_foo/bar2114=== PAUSE TestGlobMatch/*/*_foo/bar2115=== RUN TestGlobMatch/*/*_foo2116=== PAUSE TestGlobMatch/*/*_foo2117=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2118=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2119=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02120=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02121=== RUN TestGlobMatch/refs/*/main_refs/heads/main2122=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2123=== RUN TestGlobMatch/fo?_foo2124=== PAUSE TestGlobMatch/fo?_foo2125=== RUN TestGlobMatch/fo?_fo2126=== PAUSE TestGlobMatch/fo?_fo2127=== RUN TestGlobMatch/fo?_fooo2128=== PAUSE TestGlobMatch/fo?_fooo2129=== RUN TestGlobMatch/?oo_foo2130=== PAUSE TestGlobMatch/?oo_foo2131=== RUN TestGlobMatch/?oo_boo2132=== PAUSE TestGlobMatch/?oo_boo2133=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2134=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2135=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2136=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2137=== CONT TestScopes_LegacyProviderDefaultsToWrite2138=== CONT TestValidateToken_BoundSubjectMismatch2139--- PASS: TestPins_ConfigValidation (0.01s)2140=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21412026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54211/oidc2142--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)2143=== CONT TestValidateToken_NoMatchingProvider21442026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54213/oidc2145--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2146=== CONT TestPins_TopLevelShorthand21472026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54215/oidc2148--- PASS: TestValidateToken_ValidToken (0.05s)2149=== CONT TestNewValidator_KubernetesRequiresCA21502026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54217/oidc21512026/10/05 11:19:37 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232152=== CONT TestValidateToken_WrongAudience2153--- PASS: TestPins_ReservedForMatchingRule (0.06s)2154--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2155=== CONT TestScopes_ConfigValidation2156--- PASS: TestScopes_ConfigValidation (0.00s)2157=== CONT TestGlobMatch/foo_foo2158=== CONT TestGlobMatch/*/*_foo/bar2159=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2160=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2161=== CONT TestGlobMatch/?oo_boo2162=== CONT TestGlobMatch/?oo_foo2163=== CONT TestGlobMatch/fo?_fooo2164=== CONT TestGlobMatch/fo?_fo2165=== CONT TestGlobMatch/fo?_foo2166=== CONT TestGlobMatch/refs/*/main_refs/heads/main2167=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02168=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2169=== CONT TestGlobMatch/*/*_foo2170=== CONT TestGlobMatch/*bar_bar2171=== CONT TestGlobMatch/foo*bar_foobarbaz2172=== CONT TestGlobMatch/foo*bar_foo123bar2173=== CONT TestGlobMatch/foo*bar_foobar2174=== CONT TestGlobMatch/*bar_foo2175=== CONT TestGlobMatch/*bar_foobar2176=== CONT TestGlobMatch/foo*_foo2177=== CONT TestGlobMatch/foo*_bar2178=== CONT TestGlobMatch/foo*_foobar2179=== CONT TestGlobMatch/*_2180=== CONT TestGlobMatch/*_anything2181=== CONT TestGlobMatch/foo_bar2182--- PASS: TestGlobMatch (0.00s)2183 --- PASS: TestGlobMatch/foo_foo (0.00s)2184 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2185 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2186 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2187 --- PASS: TestGlobMatch/?oo_boo (0.00s)2188 --- PASS: TestGlobMatch/?oo_foo (0.00s)2189 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2190 --- PASS: TestGlobMatch/fo?_fo (0.00s)2191 --- PASS: TestGlobMatch/fo?_foo (0.00s)2192 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2194 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2195 --- PASS: TestGlobMatch/*/*_foo (0.00s)2196 --- PASS: TestGlobMatch/*bar_bar (0.00s)2197 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2198 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2199 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2200 --- PASS: TestGlobMatch/*bar_foo (0.00s)2201 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2202 --- PASS: TestGlobMatch/foo*_foo (0.00s)2203 --- PASS: TestGlobMatch/foo*_bar (0.00s)2204 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2205 --- PASS: TestGlobMatch/*_ (0.00s)2206 --- PASS: TestGlobMatch/*_anything (0.00s)2207 --- PASS: TestGlobMatch/foo_bar (0.00s)22082026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54221/oidc2209--- PASS: TestPins_TopLevelShorthand (0.03s)22102026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54224/oidc22112026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54226/oidc2212--- PASS: TestValidateToken_WrongAudience (0.02s)2213--- PASS: TestScopes_Rules (0.08s)22142026/10/05 11:19:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54210/oidc22152026/10/05 11:19:37 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54230/oidc22162026/10/05 11:19:37 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:542282217--- PASS: TestValidateToken_MultipleProviders (0.10s)2218--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)22192026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54233/oidc2220--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)22212026/10/05 11:19:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54235/oidc2222--- PASS: TestValidateToken_Expired (0.13s)22232026/10/05 11:19:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54223/oidc2224--- PASS: TestValidateToken_NoMatchingProvider (0.13s)22252026/10/05 11:19:37 http: TLS handshake error from 127.0.0.1:54240: read tcp 127.0.0.1:54239->127.0.0.1:54240: use of closed network connection2226--- PASS: TestNewValidator_KubernetesRequiresCA (0.14s)2227PASS2228Running hook tests...2229=== RUN TestSendPathsEmpty2230=== PAUSE TestSendPathsEmpty2231=== RUN TestQueueEnqueueAndFetch2232=== PAUSE TestQueueEnqueueAndFetch2233=== RUN TestQueueDeduplication2234=== PAUSE TestQueueDeduplication2235=== RUN TestQueueRemove2236=== PAUSE TestQueueRemove2237=== RUN TestQueueFetchBatchLimit2238=== PAUSE TestQueueFetchBatchLimit2239=== RUN TestQueueRetryMovesToBack2240=== PAUSE TestQueueRetryMovesToBack2241=== RUN TestQueueFetchRemoveLifecycle2242=== PAUSE TestQueueFetchRemoveLifecycle2243=== RUN TestQueueConcurrentWriters2244=== PAUSE TestQueueConcurrentWriters2245=== RUN TestQueueRemoveLargeClosure2246=== PAUSE TestQueueRemoveLargeClosure2247=== RUN TestServerClientIntegration2248=== PAUSE TestServerClientIntegration2249=== RUN TestServerQueueError2250=== PAUSE TestServerQueueError2251=== RUN TestGetListenerSocketActivation2252 server_test.go:210: === RUN TestGetListenerSocketActivation2253 --- PASS: TestGetListenerSocketActivation (0.00s)2254 PASS2255 2256--- PASS: TestGetListenerSocketActivation (0.01s)2257=== RUN TestDrainIsolatesPoisonPath2258=== PAUSE TestDrainIsolatesPoisonPath2259=== RUN TestRunNotBlockedByPoisonHead2260=== PAUSE TestRunNotBlockedByPoisonHead2261=== RUN TestDrainGivesUpWhenServerDown2262=== PAUSE TestDrainGivesUpWhenServerDown2263=== RUN TestFailedPathPrunedByLaterClosure2264=== PAUSE TestFailedPathPrunedByLaterClosure2265=== RUN TestWorkerUploadsAndRemoves2266=== PAUSE TestWorkerUploadsAndRemoves2267=== RUN TestWorkerSkipsGCdPaths2268=== PAUSE TestWorkerSkipsGCdPaths2269=== RUN TestWorkerPrunesClosureDeps2270=== PAUSE TestWorkerPrunesClosureDeps2271=== RUN TestDrainTimeout2272=== PAUSE TestDrainTimeout2273=== CONT TestSendPathsEmpty2274=== CONT TestServerQueueError2275--- PASS: TestSendPathsEmpty (0.00s)2276=== CONT TestServerClientIntegration2277=== CONT TestQueueRemoveLargeClosure2278=== CONT TestWorkerUploadsAndRemoves2279=== CONT TestDrainGivesUpWhenServerDown2280=== CONT TestFailedPathPrunedByLaterClosure2281=== CONT TestWorkerPrunesClosureDeps2282=== CONT TestWorkerSkipsGCdPaths2283=== CONT TestQueueFetchBatchLimit2284=== CONT TestDrainTimeout22852026/10/05 11:19:38 ERROR Failed to queue paths error="permission denied" count=12286--- PASS: TestServerQueueError (0.00s)2287=== CONT TestQueueEnqueueAndFetch2288--- PASS: TestServerClientIntegration (0.00s)2289=== CONT TestQueueRemove22902026/10/05 11:19:38 INFO Upload queue status pending=222912026/10/05 11:19:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-27053-1025767996/TestWorkerSkipsGCdPaths2564998099/002/nonexistent22922026/10/05 11:19:38 INFO Uploading batch count=122932026/10/05 11:19:38 INFO Uploading batch count=22294--- PASS: TestQueueEnqueueAndFetch (0.01s)2295=== CONT TestQueueDeduplication22962026/10/05 11:19:38 INFO Uploading batch count=122972026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=122982026/10/05 11:19:38 INFO Uploading batch count=222992026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=223002026/10/05 11:19:38 INFO Upload queue status pending=22301--- PASS: TestQueueFetchBatchLimit (0.01s)2302=== CONT TestRunNotBlockedByPoisonHead23032026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/a23042026/10/05 11:19:38 INFO Uploading batch count=123052026/10/05 11:19:38 INFO Upload queue status pending=223062026/10/05 11:19:38 INFO Uploading batch count=223072026/10/05 11:19:38 INFO Uploading batch count=123082026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/b2309--- PASS: TestQueueRemove (0.01s)2310=== CONT TestQueueRetryMovesToBack23112026/10/05 11:19:38 INFO Uploading batch count=123122026/10/05 11:19:38 INFO Uploading batch count=223132026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=223142026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/c23152026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/d23162026/10/05 11:19:38 INFO Uploading batch count=223172026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=223182026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/e23192026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainGivesUpWhenServerDown1184899716/002/f2320--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2321=== CONT TestQueueFetchRemoveLifecycle23222026/10/05 11:19:38 ERROR Drain finished with paths left in queue remaining=1023232026/10/05 11:19:38 INFO Upload queue status pending=323242026/10/05 11:19:38 INFO Uploading batch count=123252026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=12326--- PASS: TestQueueRetryMovesToBack (0.00s)2327=== CONT TestQueueConcurrentWriters2328--- PASS: TestQueueDeduplication (0.00s)2329=== CONT TestDrainIsolatesPoisonPath2330--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2331--- PASS: TestQueueFetchRemoveLifecycle (0.00s)23322026/10/05 11:19:38 INFO Uploading batch count=423332026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=423342026/10/05 11:19:38 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-27053-1025767996/TestDrainIsolatesPoisonPath4080821905/002/bbb23352026/10/05 11:19:38 INFO Uploading batch count=123362026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=123372026/10/05 11:19:38 INFO Uploading batch count=123382026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=123392026/10/05 11:19:38 INFO Uploading batch count=123402026/10/05 11:19:38 ERROR Upload failed error="upload failed" count=123412026/10/05 11:19:38 ERROR Drain finished with paths left in queue remaining=12342--- PASS: TestDrainIsolatesPoisonPath (0.00s)2343--- PASS: TestWorkerSkipsGCdPaths (0.03s)2344--- PASS: TestWorkerUploadsAndRemoves (0.03s)2345--- PASS: TestWorkerPrunesClosureDeps (0.03s)2346--- PASS: TestQueueRemoveLargeClosure (0.06s)2347--- PASS: TestQueueConcurrentWriters (0.14s)23482026/10/05 11:19:38 ERROR Upload failed error="context deadline exceeded" count=223492026/10/05 11:19:38 ERROR Drain finished with paths left in queue remaining=42350--- PASS: TestDrainTimeout (0.21s)23512026/10/05 11:19:39 INFO Uploading batch count=123522026/10/05 11:19:39 INFO Uploading batch count=123532026/10/05 11:19:39 INFO Uploading batch count=123542026/10/05 11:19:39 ERROR Upload failed error="upload failed" count=123552026/10/05 11:19:39 INFO Uploading batch count=123562026/10/05 11:19:39 ERROR Upload failed error="upload failed" count=123572026/10/05 11:19:39 INFO Uploading batch count=123582026/10/05 11:19:39 ERROR Upload failed error="upload failed" count=123592026/10/05 11:19:39 INFO Uploading batch count=123602026/10/05 11:19:39 ERROR Upload failed error="upload failed" count=123612026/10/05 11:19:39 ERROR Drain finished with paths left in queue remaining=12362--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2363PASS