niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #341
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestUploadMultipart_SupersededByPeer98=== CONT TestFilterOversizedClosures99--- PASS: TestEncodeNixBase32WithRealHash (0.00s)100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestResolveStorePath102=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess103=== CONT TestRateLimiterFeedback104=== CONT TestPathInfoCACompatibility105=== RUN TestUploadMultipart_SupersededByPeer/exists106=== RUN TestFilterOversizedClosures/no_limit_keeps_everything107--- PASS: TestShellSplit (0.00s)108=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything109=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped110=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped111=== RUN TestFilterOversizedClosures/all_closures_skipped112=== PAUSE TestFilterOversizedClosures/all_closures_skipped113=== RUN TestRateLimiterFeedback/429_enables_limiter114=== PAUSE TestRateLimiterFeedback/429_enables_limiter115=== RUN TestRateLimiterFeedback/503_enables_limiter116=== PAUSE TestRateLimiterFeedback/503_enables_limiter117=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter118=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter119=== CONT TestParsePathInfoJSON120=== RUN TestParsePathInfoJSON/Nix_format121=== PAUSE TestParsePathInfoJSON/Nix_format122=== RUN TestParsePathInfoJSON/Lix_format123=== PAUSE TestParsePathInfoJSON/Lix_format124=== RUN TestParsePathInfoJSON/empty_input125=== PAUSE TestParsePathInfoJSON/empty_input126=== RUN TestParsePathInfoJSON/whitespace_only127=== PAUSE TestParsePathInfoJSON/whitespace_only128=== RUN TestParsePathInfoJSON/invalid_JSON129=== PAUSE TestParsePathInfoJSON/invalid_JSON1302026/10/01 10:31:10 WARN Rate limiter enabled after throttle name=server-test rate=5131=== CONT TestGetStorePathHash132=== RUN TestGetStorePathHash/valid_store_path133=== PAUSE TestGetStorePathHash/valid_store_path134=== RUN TestGetStorePathHash/basename_without_hyphen_should_error135=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error136=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error137=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error138=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error139=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error140=== CONT TestConvertHashToNix32141=== RUN TestConvertHashToNix32/SRI_format_to_Nix32142=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32143=== RUN TestConvertHashToNix32/already_Nix32_format144=== PAUSE TestConvertHashToNix32/already_Nix32_format145=== RUN TestConvertHashToNix32/invalid_format146=== PAUSE TestConvertHashToNix32/invalid_format147=== CONT TestUploadMultipart_PartsInParallel148=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150=== CONT TestParsePathInfoJSONMultiplePaths151=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter152=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== CONT TestPathInfoHashCompatibility154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== RUN TestUploadMultipart_SupersededByPeer/missing159=== PAUSE TestUploadMultipart_SupersededByPeer/missing160=== CONT TestScriptTokenNoExpiryRerunsEveryCall161=== RUN TestPathInfoCACompatibility/null_ca_field162=== PAUSE TestPathInfoCACompatibility/null_ca_field163=== CONT TestSetClientTLSErrors164=== RUN TestPathInfoCACompatibility/old_string_format_-_text165=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text166--- PASS: TestResolveStorePath (0.00s)167=== CONT TestScriptTokenEmptyCommand168=== CONT TestScriptTokenCachesUntilRefresh169--- PASS: TestScriptTokenEmptyCommand (0.00s)170=== CONT TestScriptTokenScriptFails171=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive174=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1762026/10/01 10:31:10 WARN Rate limiter enabled after throttle name=server-test rate=51772026/10/01 10:31:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:62745178=== RUN TestPathInfoCACompatibility/new_structured_format_-_text179=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text180=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method181=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI183=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI184=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512186=== CONT TestFileTokenEmpty187=== CONT TestScriptTokenBadJSON1882026/10/01 10:31:10 WARN Rate limiter backed off name=server-test rate=51892026/10/01 10:31:10 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:62745190--- PASS: TestDoServerRequestAttachesToken (0.01s)191=== CONT TestScriptTokenEmptyToken192=== RUN TestSetClientTLSErrors/missing_cert_file193=== PAUSE TestSetClientTLSErrors/missing_cert_file194=== RUN TestSetClientTLSErrors/missing_key_file195--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)196=== PAUSE TestSetClientTLSErrors/missing_key_file197=== CONT TestFileTokenMissing198=== RUN TestSetClientTLSErrors/missing_ca_file199=== PAUSE TestSetClientTLSErrors/missing_ca_file200=== RUN TestSetClientTLSErrors/invalid_ca_file201=== PAUSE TestSetClientTLSErrors/invalid_ca_file202=== CONT TestDumpPathSingleFile203--- PASS: TestFileTokenEmpty (0.00s)204=== CONT TestEncodeNixBase32205=== RUN TestEncodeNixBase32/test_string_hash206=== PAUSE TestEncodeNixBase32/test_string_hash207=== RUN TestEncodeNixBase32/empty_input208=== PAUSE TestEncodeNixBase32/empty_input209=== CONT TestFileTokenReadsAndCaches210--- PASS: TestFileTokenMissing (0.00s)211=== CONT TestDumpPathWriterError212--- PASS: TestFileTokenReadsAndCaches (0.00s)213=== CONT TestStaticToken214--- PASS: TestStaticToken (0.00s)215=== CONT TestStreamPushRequestLine2162026/10/01 10:31:10 ERROR Upload failed error=boom count=1217--- PASS: TestScriptTokenScriptFails (0.01s)218=== CONT TestSetClientTLSDoesNotMutateDefaultTransport219--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)220=== CONT TestSetClientTLS221=== RUN TestSetClientTLS/rejects_connection_without_client_cert222=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert223=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA224=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA225=== RUN TestSetClientTLS/preserves_debug_logging_transport226=== PAUSE TestSetClientTLS/preserves_debug_logging_transport227=== CONT TestClientSignaturesByStorePath228--- PASS: TestClientSignaturesByStorePath (0.00s)229=== CONT TestStreamPushReportsSignatures2302026/10/01 10:31:10 ERROR Upload failed error=boom count=1231--- PASS: TestStreamPushReportsSignatures (0.00s)232=== CONT TestDumpPathMatchesNix233--- PASS: TestScriptTokenBadJSON (0.01s)234=== CONT TestCaseHackSuffix235--- PASS: TestScriptTokenEmptyToken (0.01s)236=== CONT TestStreamPushBatchesUnderLoad237--- PASS: TestStreamPushRequestLine (0.01s)238=== CONT TestStreamPushGivesUpOnDeadServer2392026/10/01 10:31:10 ERROR Upload failed error="connection refused" count=202402026/10/01 10:31:10 ERROR Server seems unavailable, giving up on batch untried=17241--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)242=== CONT TestStreamPushIsolatesFailures2432026/10/01 10:31:10 ERROR Upload failed error="bad path" count=3244--- PASS: TestStreamPushIsolatesFailures (0.00s)245=== CONT TestStreamPushReportsEveryPath246--- PASS: TestStreamPushReportsEveryPath (0.00s)247=== CONT TestRegisterUploadedObjectReusesConnections248--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)249=== CONT TestShellSplitErrors250--- PASS: TestShellSplitErrors (0.00s)251=== CONT TestPartSizeForNAR252=== RUN TestPartSizeForNAR/zero_stays_at_minimum253=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum254=== RUN TestPartSizeForNAR/small_stays_at_minimum255=== PAUSE TestPartSizeForNAR/small_stays_at_minimum256=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum257=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum258=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts259=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts260=== RUN TestPartSizeForNAR/1_TiB261=== PAUSE TestPartSizeForNAR/1_TiB262=== RUN TestPartSizeForNAR/5_TiB_S3_max_object263=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object264=== RUN TestPartSizeForNAR/capped_at_5_GiB265=== PAUSE TestPartSizeForNAR/capped_at_5_GiB266=== CONT TestFilterOversizedClosures/no_limit_keeps_everything267=== CONT TestFilterOversizedClosures/all_closures_skipped2682026/10/01 10:31:10 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50269--- PASS: TestDumpPathWriterError (0.04s)270=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2712026/10/01 10:31:10 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=2000272--- PASS: TestFilterOversizedClosures (0.00s)273 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)274 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)275 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)276=== CONT TestParsePathInfoJSON/Nix_format277=== CONT TestGetStorePathHash/valid_store_path278=== CONT TestParsePathInfoJSON/invalid_JSON279=== CONT TestParsePathInfoJSON/whitespace_only280=== CONT TestParsePathInfoJSON/empty_input281=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error282=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error283=== CONT TestGetStorePathHash/basename_without_hyphen_should_error284--- PASS: TestGetStorePathHash (0.00s)285 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)286 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)287 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)288 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)289=== CONT TestParsePathInfoJSON/Lix_format290=== CONT TestConvertHashToNix32/SRI_format_to_Nix32291=== CONT TestConvertHashToNix32/already_Nix32_format292=== CONT TestRateLimiterFeedback/429_enables_limiter293--- PASS: TestParsePathInfoJSON (0.00s)294 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)295 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)296 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)297 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)298 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)299=== CONT TestConvertHashToNix32/invalid_format300--- PASS: TestConvertHashToNix32 (0.00s)301 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)302 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)303 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)304=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter305=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter306--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)307=== CONT TestRateLimiterFeedback/503_enables_limiter3082026/10/01 10:31:10 WARN Rate limiter enabled after throttle name=server-test rate=53092026/10/01 10:31:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:628223102026/10/01 10:31:10 WARN Rate limiter backed off name=server-test rate=5311=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths312=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths313=== CONT TestUploadMultipart_SupersededByPeer/exists314--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)316 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)317=== CONT TestUploadMultipart_SupersededByPeer/missing3182026/10/01 10:31:10 WARN Rate limiter enabled after throttle name=server-test rate=53192026/10/01 10:31:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:628273202026/10/01 10:31:10 WARN Rate limiter backed off name=server-test rate=5321--- PASS: TestRateLimiterFeedback (0.00s)322 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)326=== CONT TestPathInfoCACompatibility/null_ca_field327=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)328=== CONT TestPathInfoCACompatibility/old_string_format_-_text329=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method330=== CONT TestPathInfoCACompatibility/new_structured_format_-_text331=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive332--- PASS: TestPathInfoCACompatibility (0.00s)333 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)334 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)336 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)338=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512339=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI340=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon341--- PASS: TestPathInfoHashCompatibility (0.00s)342 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)343 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)344 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)346=== CONT TestSetClientTLSErrors/missing_cert_file347=== CONT TestSetClientTLSErrors/missing_ca_file348=== CONT TestSetClientTLSErrors/missing_key_file349--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)350 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)351 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)352=== CONT TestSetClientTLSErrors/invalid_ca_file353=== CONT TestEncodeNixBase32/test_string_hash354=== CONT TestEncodeNixBase32/empty_input355--- PASS: TestEncodeNixBase32 (0.00s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358=== CONT TestSetClientTLS/rejects_connection_without_client_cert359=== CONT TestSetClientTLS/preserves_debug_logging_transport360=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA361--- PASS: TestSetClientTLSErrors (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)363 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)365 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)366=== CONT TestPartSizeForNAR/zero_stays_at_minimum367=== CONT TestPartSizeForNAR/capped_at_5_GiB368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts370=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum371=== CONT TestPartSizeForNAR/small_stays_at_minimum372=== CONT TestPartSizeForNAR/5_TiB_S3_max_object373--- PASS: TestPartSizeForNAR (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)378 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)3822026/10/01 10:31:10 http: TLS handshake error from 127.0.0.1:62833: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestCaseHackSuffix (0.05s)388--- PASS: TestDumpPathSingleFile (0.06s)389--- PASS: TestDumpPathMatchesNix (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-51998-174198025/postgres1691266031/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-51998-174198025/postgres1691266031/data -l logfile start421422/nix/var/nix/builds/nix-51998-174198025/postgres1691266031:5432 - no response4232026-10-01 10:31:12.079 UTC [52051] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 10:31:12.080 UTC [52051] LOG: listening on Unix socket "/nix/var/nix/builds/nix-51998-174198025/postgres1691266031/.s.PGSQL.5432"4252026-10-01 10:31:12.082 UTC [52058] LOG: database system was shut down at 2026-10-01 10:31:12 UTC4262026-10-01 10:31:12.082 UTC [52051] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-51998-174198025/postgres1691266031:5432 - accepting connections428{"timestamp":"2026-10-01T10:31:12.298405Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3113b792-60aa-468f-b0b6-97093323af42","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(11)"}429{"timestamp":"2026-10-01T10:31:12.401306Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8ee14c2e-db32-494d-9634-e0b2f51e1552","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026/10/01 10:31:12 INFO lead: acquired remote=192.0.2.1:12344742026/10/01 10:31:13 INFO lead: released remote=192.0.2.1:12344752026/10/01 10:31:13 INFO lead: acquired remote=192.0.2.1:12344762026/10/01 10:31:13 INFO lead: released remote=192.0.2.1:1234477--- PASS: TestLeadIncumbentWinsAfterRestart (0.82s)478=== RUN TestLeadEndsOnShutdown479=== PAUSE TestLeadEndsOnShutdown480=== RUN TestGCAdvisoryLockBlocksConcurrentRun481=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun482=== RUN TestGCBugBareHashReferences483=== PAUSE TestGCBugBareHashReferences484=== RUN TestGCMetrics485=== PAUSE TestGCMetrics486=== RUN TestPushDedupSurvivesConcurrentGC487=== PAUSE TestPushDedupSurvivesConcurrentGC488=== RUN TestDeduplicatedObjectsRecordedAsPending489=== PAUSE TestDeduplicatedObjectsRecordedAsPending490=== RUN TestGCSweepSkipsPendingObjects491=== PAUSE TestGCSweepSkipsPendingObjects492=== RUN TestTombstonedObjectOfferedWithoutWaiting493=== PAUSE TestTombstonedObjectOfferedWithoutWaiting494=== RUN TestGCSweepDeliversEachKeyOnce495=== PAUSE TestGCSweepDeliversEachKeyOnce496=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection497=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection498=== RUN TestForceGCDuringPushOffersSweptObject499=== PAUSE TestForceGCDuringPushOffersSweptObject500=== RUN TestFailedS3DeleteKeepsTombstone501=== PAUSE TestFailedS3DeleteKeepsTombstone502=== RUN TestSweepSkipsRowsLockedByPush503=== PAUSE TestSweepSkipsRowsLockedByPush504=== RUN TestRegisterCompletedObjectNeedsPendingRow505=== PAUSE TestRegisterCompletedObjectNeedsPendingRow506=== RUN TestGetExistingObjectsLocksRows507=== PAUSE TestGetExistingObjectsLocksRows508=== RUN TestSweepRechecksPendingAfterLocking509=== PAUSE TestSweepRechecksPendingAfterLocking510=== RUN TestPushWaitsForSweepHoldingRow511=== PAUSE TestPushWaitsForSweepHoldingRow512=== RUN TestCommitRacingPendingCleanupKeepsObjects513=== PAUSE TestCommitRacingPendingCleanupKeepsObjects514=== RUN TestGCEndsOnShutdown515=== PAUSE TestGCEndsOnShutdown516=== RUN TestGCTaskStore_StartNew517=== PAUSE TestGCTaskStore_StartNew518=== RUN TestGCTaskStore_DeduplicateSameParams519=== PAUSE TestGCTaskStore_DeduplicateSameParams520=== RUN TestGCTaskStore_ConflictDifferentParams521=== PAUSE TestGCTaskStore_ConflictDifferentParams522=== RUN TestGCTaskStore_GetEmpty523=== PAUSE TestGCTaskStore_GetEmpty524=== RUN TestGCTaskStore_GetReturnsLatest525=== PAUSE TestGCTaskStore_GetReturnsLatest526=== RUN TestGCTaskStore_CompletedAllowsNewTask527=== PAUSE TestGCTaskStore_CompletedAllowsNewTask528=== RUN TestGCTaskStore_PhaseUpdates529=== PAUSE TestGCTaskStore_PhaseUpdates530=== RUN TestGCTaskStore_Fail531=== PAUSE TestGCTaskStore_Fail532=== RUN TestGracefulShutdownDrainsInflight533=== PAUSE TestGracefulShutdownDrainsInflight534=== RUN TestService_healthCheckHandler535=== PAUSE TestService_healthCheckHandler536=== RUN TestService_readinessHandler537=== PAUSE TestService_readinessHandler538=== RUN TestGenerateLandingPage539=== PAUSE TestGenerateLandingPage540=== RUN TestCacheConfigHandlerMaxNarSize541=== PAUSE TestCacheConfigHandlerMaxNarSize542=== RUN TestCreatePendingClosureRejectsOversizedNAR543=== PAUSE TestCreatePendingClosureRejectsOversizedNAR544=== RUN TestNARDeduplicationMetadataUploadBug545=== PAUSE TestNARDeduplicationMetadataUploadBug546=== RUN TestMetricsInventory547=== PAUSE TestMetricsInventory548=== RUN TestService_NativeMTLS549=== PAUSE TestService_NativeMTLS550=== RUN TestServerTLSConfig551=== PAUSE TestServerTLSConfig552=== RUN TestMultipartCleanup553=== PAUSE TestMultipartCleanup554=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded555=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded556=== RUN TestPendingCleanupUsesOneCutoff557=== PAUSE TestPendingCleanupUsesOneCutoff558=== RUN TestObjectStatsTrigger559=== PAUSE TestObjectStatsTrigger560=== RUN TestOrphanedObjectsGC561=== PAUSE TestOrphanedObjectsGC562=== RUN TestOrphanedObjectsGCStressTest563=== PAUSE TestOrphanedObjectsGCStressTest564=== RUN TestCreatePin_ReservedPins565=== PAUSE TestCreatePin_ReservedPins566=== RUN TestPresentReportsOnlyClosureRoots567=== PAUSE TestPresentReportsOnlyClosureRoots568=== RUN TestPresentNotReportedWhileGCDeletesClosure569=== PAUSE TestPresentNotReportedWhileGCDeletesClosure570=== RUN TestParseSingleRange571=== PAUSE TestParseSingleRange572=== RUN TestProxyHeadersOnlyTrustedOnSocket573=== PAUSE TestProxyHeadersOnlyTrustedOnSocket574=== RUN TestIsValidCachePath575=== PAUSE TestIsValidCachePath576=== RUN TestReadProxyNarinfo577=== PAUSE TestReadProxyNarinfo578=== RUN TestReadProxyNarinfoAlreadyDecompressed579=== PAUSE TestReadProxyNarinfoAlreadyDecompressed580=== RUN TestReadProxyNarStreaming581=== PAUSE TestReadProxyNarStreaming582=== RUN TestReadProxy404583=== PAUSE TestReadProxy404584=== RUN TestReadProxyInvalidPath585=== PAUSE TestReadProxyInvalidPath586=== RUN TestReadProxyHead587=== PAUSE TestReadProxyHead588=== RUN TestReadProxyOutlastsServerWriteTimeout589=== PAUSE TestReadProxyOutlastsServerWriteTimeout590=== RUN TestReadProxyConditionalGet591=== PAUSE TestReadProxyConditionalGet592=== RUN TestReadProxyRootRedirectsToIndexHTML593=== PAUSE TestReadProxyRootRedirectsToIndexHTML594=== RUN TestReadProxyDisabled595=== PAUSE TestReadProxyDisabled596=== RUN TestReadRedirectNar597=== PAUSE TestReadRedirectNar598=== RUN TestReadRedirectKeepsNarinfoProxied599=== PAUSE TestReadRedirectKeepsNarinfoProxied600=== RUN TestReadProxyRangeRequest601=== PAUSE TestReadProxyRangeRequest602=== RUN TestReadRedirectUsesPublicS3URL603=== PAUSE TestReadRedirectUsesPublicS3URL604=== RUN TestPush_OverlappingRootsStoreOneRowPerKey605=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey606=== RUN TestPush_CompleteCommitsEveryRoot607=== PAUSE TestPush_CompleteCommitsEveryRoot608=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit609=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit610=== RUN TestPush_RejectsBadRequests611=== PAUSE TestPush_RejectsBadRequests612=== RUN TestPush_SignsNarinfosOfItsPendingObjects613=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects614=== RUN TestRedundantMultipartUpload615=== PAUSE TestRedundantMultipartUpload616=== RUN TestCompleteMultipartUpload_ErrorButObjectExists617=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists618=== RUN TestCompletedNarNotReofferedAcrossClosures619=== PAUSE TestCompletedNarNotReofferedAcrossClosures620=== RUN TestPresignedUploadRegisteredBeforeCommit621=== PAUSE TestPresignedUploadRegisteredBeforeCommit622=== RUN TestService_Rustfstest623=== PAUSE TestService_Rustfstest624=== RUN TestParseSize625=== PAUSE TestParseSize626=== RUN TestSkippedUploadsHandler627=== PAUSE TestSkippedUploadsHandler628=== RUN TestSystemdListenerNotActivated629--- PASS: TestSystemdListenerNotActivated (0.00s)630=== RUN TestWatchdogBeatsWhenHealthy631--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)632=== RUN TestWatchdogSkipsWhenUnhealthy6332026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 10:31:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"643--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)644=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle646=== RUN TestProxyWriteTimeout647=== PAUSE TestProxyWriteTimeout648=== RUN TestPendingClosureWriteTimeout649=== PAUSE TestPendingClosureWriteTimeout650=== RUN TestIsValidUploadKey651=== PAUSE TestIsValidUploadKey652=== RUN TestUploadHandlersRejectInvalidKeys653=== PAUSE TestUploadHandlersRejectInvalidKeys654=== RUN TestUploadHandlersRejectOversizedBody655=== PAUSE TestUploadHandlersRejectOversizedBody656=== RUN TestService_cleanupPendingClosuresHandler657=== PAUSE TestService_cleanupPendingClosuresHandler658=== RUN TestService_createPendingClosureHandler659=== PAUSE TestService_createPendingClosureHandler660=== RUN TestService_verifyS3Integrity661=== PAUSE TestService_verifyS3Integrity662=== RUN TestCompleteMultipartUnregistered663=== PAUSE TestCompleteMultipartUnregistered664=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT665=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT666=== CONT TestReadProxyConditionalGet667=== CONT TestRegisterCompletedObjectNeedsPendingRow668=== CONT TestService_AuthMiddleware669=== CONT TestReadProxyOutlastsServerWriteTimeout670=== CONT TestReadProxyHead671=== CONT TestReadProxyInvalidPath672=== CONT TestReadProxy404673=== CONT TestReadProxyNarStreaming674=== CONT TestReadProxyNarinfoAlreadyDecompressed675=== CONT TestGetExistingObjectsLocksRows676--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.47s)677=== CONT TestSweepRechecksPendingAfterLocking678--- PASS: TestReadProxy404 (0.68s)679=== CONT TestReadProxyNarinfo6802026/10/01 10:31:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"681--- PASS: TestService_AuthMiddleware (0.81s)682=== CONT TestIsValidCachePath683=== RUN TestIsValidCachePath/narinfo684=== PAUSE TestIsValidCachePath/narinfo685=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars686=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars687=== RUN TestIsValidCachePath/nar_zst688=== PAUSE TestIsValidCachePath/nar_zst689=== RUN TestIsValidCachePath/nar_xz690=== PAUSE TestIsValidCachePath/nar_xz691=== RUN TestIsValidCachePath/nar_bz2692=== PAUSE TestIsValidCachePath/nar_bz2693=== RUN TestIsValidCachePath/nar_uncompressed694=== PAUSE TestIsValidCachePath/nar_uncompressed695=== RUN TestIsValidCachePath/ls696=== PAUSE TestIsValidCachePath/ls697=== RUN TestIsValidCachePath/log698=== PAUSE TestIsValidCachePath/log699=== RUN TestIsValidCachePath/realisation700=== PAUSE TestIsValidCachePath/realisation701=== RUN TestIsValidCachePath/nix-cache-info702=== PAUSE TestIsValidCachePath/nix-cache-info703=== RUN TestIsValidCachePath/index.html704=== PAUSE TestIsValidCachePath/index.html705=== RUN TestIsValidCachePath/traversal_parent706=== PAUSE TestIsValidCachePath/traversal_parent707=== RUN TestIsValidCachePath/traversal_in_middle708=== PAUSE TestIsValidCachePath/traversal_in_middle709=== RUN TestIsValidCachePath/invalid_char_e710=== PAUSE TestIsValidCachePath/invalid_char_e711=== RUN TestIsValidCachePath/invalid_char_u712=== PAUSE TestIsValidCachePath/invalid_char_u713=== RUN TestIsValidCachePath/random_path714=== PAUSE TestIsValidCachePath/random_path715=== RUN TestIsValidCachePath/empty716=== PAUSE TestIsValidCachePath/empty717=== RUN TestIsValidCachePath/leading_slash718=== PAUSE TestIsValidCachePath/leading_slash719=== RUN TestIsValidCachePath/wrong_extension720=== PAUSE TestIsValidCachePath/wrong_extension721=== RUN TestIsValidCachePath/short_hash722=== PAUSE TestIsValidCachePath/short_hash723=== CONT TestProxyHeadersOnlyTrustedOnSocket724--- PASS: TestReadProxyInvalidPath (0.95s)725=== CONT TestParseSingleRange726=== RUN TestParseSingleRange/none727=== PAUSE TestParseSingleRange/none728=== RUN TestParseSingleRange/unknown_unit729=== PAUSE TestParseSingleRange/unknown_unit730=== RUN TestParseSingleRange/multi-range_ignored731=== PAUSE TestParseSingleRange/multi-range_ignored732=== RUN TestParseSingleRange/malformed_no_dash733=== PAUSE TestParseSingleRange/malformed_no_dash734=== RUN TestParseSingleRange/malformed_both_empty735=== PAUSE TestParseSingleRange/malformed_both_empty736=== RUN TestParseSingleRange/malformed_end_before_start737=== PAUSE TestParseSingleRange/malformed_end_before_start738=== RUN TestParseSingleRange/closed739=== PAUSE TestParseSingleRange/closed740=== RUN TestParseSingleRange/open-ended741=== PAUSE TestParseSingleRange/open-ended742=== RUN TestParseSingleRange/end_clamped_to_size743=== PAUSE TestParseSingleRange/end_clamped_to_size744=== RUN TestParseSingleRange/suffix745=== PAUSE TestParseSingleRange/suffix746=== RUN TestParseSingleRange/suffix_exceeds_size747=== PAUSE TestParseSingleRange/suffix_exceeds_size748=== RUN TestParseSingleRange/single_byte749=== PAUSE TestParseSingleRange/single_byte750=== RUN TestParseSingleRange/start_past_EOF751=== PAUSE TestParseSingleRange/start_past_EOF752=== RUN TestParseSingleRange/start_far_past_EOF753=== PAUSE TestParseSingleRange/start_far_past_EOF754=== CONT TestPresentNotReportedWhileGCDeletesClosure755--- PASS: TestReadProxyHead (1.14s)756=== CONT TestPresentReportsOnlyClosureRoots757--- PASS: TestGetExistingObjectsLocksRows (1.53s)758=== CONT TestCreatePin_ReservedPins7592026/10/01 10:31:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62877/oidc760--- PASS: TestReadProxyNarStreaming (1.71s)761=== CONT TestOrphanedObjectsGCStressTest762--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.88s)763=== CONT TestOrphanedObjectsGC764--- PASS: TestReadProxyConditionalGet (2.05s)765=== CONT TestObjectStatsTrigger7662026/10/01 10:31:15 INFO Aborted multipart uploads count=0 kept=07672026/10/01 10:31:15 WARN Force mode enabled - objects will be deleted immediately without grace period7682026/10/01 10:31:15 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=07692026/10/01 10:31:15 INFO Vacuumed table table=pending_closures7702026/10/01 10:31:15 INFO Vacuumed table table=pending_objects7712026/10/01 10:31:15 INFO Vacuumed table table=multipart_uploads7722026/10/01 10:31:15 INFO Vacuumed table table=closures7732026/10/01 10:31:15 INFO Vacuumed table table=objects774--- PASS: TestSweepRechecksPendingAfterLocking (1.82s)775=== CONT TestPendingCleanupUsesOneCutoff7762026/10/01 10:31:15 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"7772026/10/01 10:31:16 INFO Starting HTTP server address=/nix/var/nix/builds/nix-51998-174198025/TestProxyHeadersOnlyTrustedOnSocket706535755/001/proxy.sock7782026/10/01 10:31:16 INFO Starting HTTP server address=127.0.0.1:628997792026/10/01 10:31:16 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7802026/10/01 10:31:16 INFO Shutdown signal received, draining in-flight requests timeout=10s781--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.81s)782=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded7832026/10/01 10:31:16 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216784--- PASS: TestReadProxyNarinfo (2.01s)785=== CONT TestMultipartCleanup786--- PASS: TestPresentReportsOnlyClosureRoots (1.90s)787=== CONT TestServerTLSConfig788=== RUN TestServerTLSConfig/no_client_CA789=== PAUSE TestServerTLSConfig/no_client_CA790=== RUN TestServerTLSConfig/missing_CA_file791=== PAUSE TestServerTLSConfig/missing_CA_file792=== RUN TestServerTLSConfig/not_a_PEM_file793=== PAUSE TestServerTLSConfig/not_a_PEM_file794=== CONT TestService_NativeMTLS7952026/10/01 10:31:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7962026/10/01 10:31:16 WARN Refused reserved pin name=worker-x86_64-linux7972026/10/01 10:31:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7982026/10/01 10:31:16 INFO Received create pin request method=POST path=/api/pins/my-app7992026/10/01 10:31:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux800--- PASS: TestCreatePin_ReservedPins (1.66s)801=== CONT TestMetricsInventory802--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.38s)803=== CONT TestClientFallsBackToClosures804--- PASS: TestObjectStatsTrigger (1.82s)805=== CONT TestSweepSkipsRowsLockedByPush8062026/10/01 10:31:17 INFO Received uploads request method=POST path=/api/pending_closures8072026/10/01 10:31:17 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/01 10:31:17 INFO Received cleanup request method=DELETE path=/api/pending_closures809=== NAME TestOrphanedObjectsGC810 orphaned_objects_gc_test.go:290: GC Test Summary:811 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A812 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B813 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)814 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)815 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects816--- PASS: TestOrphanedObjectsGC (2.29s)817=== CONT TestFailedS3DeleteKeepsTombstone8182026/10/01 10:31:17 INFO Received uploads request method=POST path=/api/pending_closures8192026/10/01 10:31:18 INFO Received cleanup request method=DELETE path=/api/pending_closures8202026/10/01 10:31:18 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket22/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8212026/10/01 10:31:18 INFO Aborted multipart uploads count=0 kept=18222026/10/01 10:31:18 INFO Received cleanup request method=DELETE path=/api/pending_closures8232026/10/01 10:31:18 INFO Aborted multipart uploads count=1 kept=0824--- PASS: TestMultipartCleanup (1.94s)825=== CONT TestForceGCDuringPushOffersSweptObject826=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows827=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows828=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check829=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check830=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8312026/10/01 10:31:18 INFO Received uploads request method=POST path=/api/pending_closures832--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.12s)833=== CONT TestGCSweepDeliversEachKeyOnce8342026/10/01 10:31:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8352026/10/01 10:31:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"836--- PASS: TestService_NativeMTLS (1.92s)837=== CONT TestNARDeduplicationMetadataUploadBug838--- PASS: TestMetricsInventory (2.06s)839=== CONT TestTombstonedObjectOfferedWithoutWaiting840--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.55s)841=== CONT TestGCSweepSkipsPendingObjects8422026/10/01 10:31:19 INFO Received uploads request method=POST path=/api/pending_closures8432026/10/01 10:31:19 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/01 10:31:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8452026/10/01 10:31:19 INFO Uploading 4yd1v7zhnvmv82777cdfb6j5aywxr7hx-a (248B)8462026/10/01 10:31:19 INFO Uploading 6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1-shared-dep (136B)8472026/10/01 10:31:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8482026/10/01 10:31:19 WARN Failed to register uploaded object key=6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1.ls error="server returned 404: 404 page not found\n"8492026/10/01 10:31:19 WARN Failed to register uploaded object key=nar/1dyaiv7x7ja50x48q2xsm469f4ribxdrmcl44fc21905ml289r79.nar.zst error="server returned 404: 404 page not found\n"8502026/10/01 10:31:19 WARN Failed to register uploaded object key=i2jfarvmxdwyp65jgg56byiraqmdmjx0.ls error="server returned 404: 404 page not found\n"8512026/10/01 10:31:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8522026/10/01 10:31:19 WARN Failed to register uploaded object key=4yd1v7zhnvmv82777cdfb6j5aywxr7hx.ls error="server returned 404: 404 page not found\n"8532026/10/01 10:31:19 INFO Signed narinfos id=1 count=28542026/10/01 10:31:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8552026/10/01 10:31:19 INFO Signed narinfos id=2 count=28562026/10/01 10:31:19 INFO Uploading 4 narinfos8572026/10/01 10:31:19 WARN Failed to register uploaded object key=4yd1v7zhnvmv82777cdfb6j5aywxr7hx.narinfo error="server returned 404: 404 page not found\n"8582026/10/01 10:31:19 WARN Failed to register uploaded object key=i2jfarvmxdwyp65jgg56byiraqmdmjx0.narinfo error="server returned 404: 404 page not found\n"8592026/10/01 10:31:19 WARN Failed to register uploaded object key=6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1.narinfo error="server returned 404: 404 page not found\n"8602026/10/01 10:31:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8612026/10/01 10:31:19 WARN Failed to register uploaded object key=6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1.narinfo error="server returned 404: 404 page not found\n"8622026/10/01 10:31:19 INFO Aborted multipart uploads count=0 kept=08632026/10/01 10:31:19 WARN Force mode enabled - objects will be deleted immediately without grace period8642026/10/01 10:31:19 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=08652026/10/01 10:31:19 INFO Vacuumed table table=pending_closures8662026/10/01 10:31:19 INFO Vacuumed table table=pending_objects8672026/10/01 10:31:19 INFO Vacuumed table table=multipart_uploads8682026/10/01 10:31:19 INFO Vacuumed table table=closures8692026/10/01 10:31:19 INFO Completed upload id=18702026/10/01 10:31:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8712026/10/01 10:31:19 INFO Completed upload id=28722026/10/01 10:31:19 INFO Upload complete. (212ms)873=== NAME TestClientFallsBackToClosures874 client_pushes_test.go:112: Retrieved narinfo from S3:875 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientFallsBackToClosures2086342174/001/store/6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1-shared-dep876 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst877 Compression: zstd878 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82879 NarSize: 136880 References: 881 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n882 client_pushes_test.go:112: Retrieved narinfo from S3:883 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientFallsBackToClosures2086342174/001/store/4yd1v7zhnvmv82777cdfb6j5aywxr7hx-a884 URL: nar/1dyaiv7x7ja50x48q2xsm469f4ribxdrmcl44fc21905ml289r79.nar.zst885 Compression: zstd886 NarHash: sha256:1dyaiv7x7ja50x48q2xsm469f4ribxdrmcl44fc21905ml289r79887 NarSize: 248888 References: /nix/var/nix/builds/nix-51998-174198025/TestClientFallsBackToClosures2086342174/001/store/6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1-shared-dep889 CA: text:sha256:0iwr25ijfb200fm1cb1mf8y3hak25gqxzdrfzd3vnl6d9al5plhi890 client_pushes_test.go:112: Retrieved narinfo from S3:891 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientFallsBackToClosures2086342174/001/store/i2jfarvmxdwyp65jgg56byiraqmdmjx0-b892 URL: nar/1dyaiv7x7ja50x48q2xsm469f4ribxdrmcl44fc21905ml289r79.nar.zst893 Compression: zstd894 NarHash: sha256:1dyaiv7x7ja50x48q2xsm469f4ribxdrmcl44fc21905ml289r79895 NarSize: 248896 References: /nix/var/nix/builds/nix-51998-174198025/TestClientFallsBackToClosures2086342174/001/store/6iwcq38ylzjsiy0f1dbdqjgg3as7kmk1-shared-dep897 CA: text:sha256:0iwr25ijfb200fm1cb1mf8y3hak25gqxzdrfzd3vnl6d9al5plhi8982026/10/01 10:31:19 INFO Vacuumed table table=objects8992026/10/01 10:31:19 INFO Aborted multipart uploads count=0 kept=09002026/10/01 10:31:19 WARN Force mode enabled - objects will be deleted immediately without grace period901--- PASS: TestClientFallsBackToClosures (2.92s)902=== CONT TestCreatePendingClosureRejectsOversizedNAR9032026/10/01 10:31:19 INFO Received uploads request method=POST path=/api/pending_closures904--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)905=== CONT TestDeduplicatedObjectsRecordedAsPending9062026/10/01 10:31:19 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=09072026/10/01 10:31:19 INFO Vacuumed table table=pending_closures9082026/10/01 10:31:19 INFO Vacuumed table table=pending_objects9092026/10/01 10:31:19 INFO Vacuumed table table=multipart_uploads9102026/10/01 10:31:19 INFO Vacuumed table table=closures9112026/10/01 10:31:19 INFO Vacuumed table table=objects912=== CONT TestCacheConfigHandlerMaxNarSize913--- PASS: TestSweepSkipsRowsLockedByPush (2.40s)914--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)915=== CONT TestPushDedupSurvivesConcurrentGC9162026/10/01 10:31:20 INFO Received uploads request method=POST path=/api/pending_closures9172026/10/01 10:31:20 INFO Aborted multipart uploads count=0 kept=09182026/10/01 10:31:20 WARN Force mode enabled - objects will be deleted immediately without grace period9192026/10/01 10:31:20 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9202026/10/01 10:31:20 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."921--- PASS: TestFailedS3DeleteKeepsTombstone (2.67s)922=== CONT TestGenerateLandingPage923--- PASS: TestGenerateLandingPage (0.00s)924=== CONT TestGCMetrics9252026/10/01 10:31:20 INFO Received uploads request method=POST path=/api/pending_closures926--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.78s)927=== CONT TestService_readinessHandler9282026/10/01 10:31:21 INFO Aborted multipart uploads count=0 kept=09292026/10/01 10:31:21 WARN Force mode enabled - objects will be deleted immediately without grace period9302026/10/01 10:31:21 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=09312026/10/01 10:31:21 INFO Vacuumed table table=pending_closures9322026/10/01 10:31:21 INFO Vacuumed table table=pending_objects9332026/10/01 10:31:21 INFO Vacuumed table table=multipart_uploads9342026/10/01 10:31:21 INFO Vacuumed table table=closures9352026/10/01 10:31:21 INFO Vacuumed table table=objects936--- PASS: TestGCSweepDeliversEachKeyOnce (3.01s)937=== CONT TestGCBugBareHashReferences938=== NAME TestNARDeduplicationMetadataUploadBug939 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-51998-174198025/TestNARDeduplicationMetadataUploadBug3567555841/001/store/6nic1nmsb543118zjsrkmiy1dm31hq7q-file1.txt9402026/10/01 10:31:21 INFO Received uploads request method=POST path=/api/pending_closures941--- PASS: TestTombstonedObjectOfferedWithoutWaiting (3.00s)942=== CONT TestService_healthCheckHandler9432026/10/01 10:31:21 INFO Received push request method=POST path=/api/pushes9442026/10/01 10:31:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9452026/10/01 10:31:21 INFO Uploading 6nic1nmsb543118zjsrkmiy1dm31hq7q-file1.txt (160B)9462026/10/01 10:31:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9472026/10/01 10:31:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9482026/10/01 10:31:21 WARN Failed to register uploaded object key=6nic1nmsb543118zjsrkmiy1dm31hq7q.ls error="server returned 404: 404 page not found\n"9492026/10/01 10:31:21 INFO Signed narinfos id=1 count=19502026/10/01 10:31:21 INFO Uploading 1 narinfos9512026/10/01 10:31:21 INFO Received complete push request method=POST path=/api/pushes/1/complete9522026/10/01 10:31:21 WARN Failed to register uploaded object key=6nic1nmsb543118zjsrkmiy1dm31hq7q.narinfo error="server returned 404: 404 page not found\n"9532026/10/01 10:31:21 INFO Upload complete. (160ms)954=== NAME TestNARDeduplicationMetadataUploadBug955 metadata_upload_test.go:54: Retrieved narinfo from S3:956 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestNARDeduplicationMetadataUploadBug3567555841/001/store/6nic1nmsb543118zjsrkmiy1dm31hq7q-file1.txt957 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst958 Compression: zstd959 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf960 NarSize: 160961 References: 962 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf963 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)964 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):965 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}966 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-51998-174198025/TestNARDeduplicationMetadataUploadBug3567555841/001/store/4r740axh15gpv9s2nzc2zkl10v3f103v-file2.txt9672026/10/01 10:31:22 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/01 10:31:22 INFO Aborted multipart uploads count=0 kept=09692026/10/01 10:31:22 WARN Force mode enabled - objects will be deleted immediately without grace period9702026/10/01 10:31:22 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=0971=== NAME TestOrphanedObjectsGCStressTest972 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains9732026/10/01 10:31:22 INFO Received push request method=POST path=/api/pushes9742026/10/01 10:31:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9752026/10/01 10:31:22 INFO Vacuumed table table=pending_closures9762026/10/01 10:31:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9772026/10/01 10:31:22 INFO Signed narinfos id=2 count=19782026/10/01 10:31:22 INFO Uploading 1 narinfos9792026/10/01 10:31:22 WARN Failed to register uploaded object key=4r740axh15gpv9s2nzc2zkl10v3f103v.ls error="server returned 404: 404 page not found\n"9802026/10/01 10:31:22 INFO Received complete push request method=POST path=/api/pushes/2/complete9812026/10/01 10:31:22 WARN Failed to register uploaded object key=4r740axh15gpv9s2nzc2zkl10v3f103v.narinfo error="server returned 404: 404 page not found\n"9822026/10/01 10:31:22 INFO Vacuumed table table=pending_objects9832026/10/01 10:31:22 INFO Upload complete. (59ms)984=== NAME TestNARDeduplicationMetadataUploadBug985 metadata_upload_test.go:76: Retrieved narinfo from S3:986 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestNARDeduplicationMetadataUploadBug3567555841/001/store/4r740axh15gpv9s2nzc2zkl10v3f103v-file2.txt987 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst988 Compression: zstd989 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf990 NarSize: 160991 References: 992 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf993 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)994 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):995 {"version":1,"root":{"type":"regular","size":44}}9962026/10/01 10:31:22 INFO Vacuumed table table=multipart_uploads9972026/10/01 10:31:22 INFO Vacuumed table table=closures9982026/10/01 10:31:22 INFO Vacuumed table table=objects999=== NAME TestOrphanedObjectsGCStressTest1000 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1001--- PASS: TestNARDeduplicationMetadataUploadBug (3.64s)1002=== CONT TestGCAdvisoryLockBlocksConcurrentRun1003--- PASS: TestGCSweepSkipsPendingObjects (3.06s)1004=== CONT TestGracefulShutdownDrainsInflight10052026/10/01 10:31:22 INFO Starting HTTP server address=127.0.0.1:6298310062026/10/01 10:31:22 INFO Shutdown signal received, draining in-flight requests timeout=10s1007--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1008=== CONT TestLeadEndsOnShutdown10092026/10/01 10:31:22 INFO Received uploads request method=POST path=/api/pending_closures1010--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.52s)1011=== CONT TestGCTaskStore_Fail1012--- PASS: TestGCTaskStore_Fail (0.00s)1013=== CONT TestGCTaskStore_PhaseUpdates1014--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1015=== CONT TestLeadElectsOneAndHandsOver10162026/10/01 10:31:22 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/01 10:31:22 INFO Aborted multipart uploads count=0 kept=010182026/10/01 10:31:22 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010192026/10/01 10:31:22 INFO Vacuumed table table=pending_closures10202026/10/01 10:31:22 INFO Vacuumed table table=pending_objects10212026/10/01 10:31:22 INFO Vacuumed table table=multipart_uploads10222026/10/01 10:31:22 INFO Vacuumed table table=closures10232026/10/01 10:31:22 INFO Aborted multipart uploads count=0 kept=010242026/10/01 10:31:22 WARN Force mode enabled - objects will be deleted immediately without grace period10252026/10/01 10:31:22 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=010262026/10/01 10:31:22 INFO Vacuumed table table=pending_closures10272026/10/01 10:31:22 INFO Vacuumed table table=pending_objects10282026/10/01 10:31:22 INFO Vacuumed table table=multipart_uploads10292026/10/01 10:31:22 INFO Vacuumed table table=closures10302026/10/01 10:31:22 INFO Vacuumed table table=objects10312026/10/01 10:31:22 INFO Vacuumed table table=objects1032--- PASS: TestGCMetrics (2.37s)1033=== CONT TestGCTaskStore_CompletedAllowsNewTask1034--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1035=== CONT TestGCTaskStore_GetReturnsLatest1036--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1037=== CONT TestGCTaskStore_GetEmpty1038--- PASS: TestGCTaskStore_GetEmpty (0.00s)1039=== CONT TestGCTaskStore_ConflictDifferentParams1040--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1041=== CONT TestGCTaskStore_DeduplicateSameParams1042--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1043=== CONT TestGCTaskStore_StartNew1044--- PASS: TestGCTaskStore_StartNew (0.00s)1045=== CONT TestGCEndsOnShutdown10462026/10/01 10:31:22 INFO Aborted multipart uploads count=0 kept=010472026/10/01 10:31:22 WARN Force mode enabled - objects will be deleted immediately without grace period10482026/10/01 10:31:22 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=010492026/10/01 10:31:22 INFO Vacuumed table table=pending_closures10502026/10/01 10:31:22 INFO Vacuumed table table=pending_objects10512026/10/01 10:31:22 INFO Vacuumed table table=multipart_uploads10522026/10/01 10:31:22 INFO Vacuumed table table=closures10532026/10/01 10:31:22 INFO Vacuumed table table=objects1054--- PASS: TestPushDedupSurvivesConcurrentGC (3.02s)1055=== CONT TestCommitRacingPendingCleanupKeepsObjects10562026/10/01 10:31:22 WARN readiness check failed error="closed pool"1057--- PASS: TestService_readinessHandler (1.98s)1058=== CONT TestPushWaitsForSweepHoldingRow1059--- PASS: TestGCBugBareHashReferences (2.15s)1060=== CONT TestClientCADerivations1061--- PASS: TestService_healthCheckHandler (1.66s)1062=== CONT TestResolveDBConnectionString1063=== RUN TestResolveDBConnectionString/flag_wins1064=== PAUSE TestResolveDBConnectionString/flag_wins1065=== RUN TestResolveDBConnectionString/file_when_flag_empty1066=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1067=== RUN TestResolveDBConnectionString/missing_file_is_an_error1068=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1069=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1070=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1071=== RUN TestResolveDBConnectionString/nothing_configured1072=== PAUSE TestResolveDBConnectionString/nothing_configured1073=== CONT TestClientPushesUseOnePush10742026/10/01 10:31:23 INFO Aborted multipart uploads count=1 kept=010752026/10/01 10:31:23 INFO Received cleanup request method=DELETE path=/api/pending_closures10762026/10/01 10:31:23 INFO Aborted multipart uploads count=1 kept=01077--- PASS: TestPendingCleanupUsesOneCutoff (7.94s)1078=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1079--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.65s)1080=== CONT TestPinProtectsFromGC1081=== NAME TestOrphanedObjectsGCStressTest1082 orphaned_objects_gc_test.go:509: Stress test completed successfully:1083 orphaned_objects_gc_test.go:510: - Active objects preserved: 201084 orphaned_objects_gc_test.go:511: - Objects deleted: 2101085 orphaned_objects_gc_test.go:512: - Total GC'd: 2101086--- PASS: TestOrphanedObjectsGCStressTest (8.75s)1087=== CONT TestClientSharedPathCommittedMidPush10882026/10/01 10:31:24 INFO lead: acquired remote=192.0.2.1:123410892026/10/01 10:31:24 INFO lead: released remote=192.0.2.1:123410902026/10/01 10:31:24 INFO lead: acquired remote=192.0.2.1:123410912026/10/01 10:31:24 INFO lead: released remote=192.0.2.1:12341092--- PASS: TestLeadElectsOneAndHandsOver (1.98s)1093=== CONT TestService_RequireScope_OIDC10942026/10/01 10:31:24 INFO lead: acquired remote=192.0.2.1:123410952026/10/01 10:31:24 INFO lead: released remote=192.0.2.1:12341096--- PASS: TestLeadEndsOnShutdown (2.10s)1097=== CONT TestClientWithDependencies10982026/10/01 10:31:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63003/oidc1099--- PASS: TestGCEndsOnShutdown (1.80s)1100=== CONT TestClientMultipleUploads11012026/10/01 10:31:24 INFO Aborted multipart uploads count=0 kept=011022026/10/01 10:31:24 WARN Force mode enabled - objects will be deleted immediately without grace period11032026/10/01 10:31: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=011042026/10/01 10:31:24 INFO Vacuumed table table=pending_closures11052026/10/01 10:31:24 INFO Vacuumed table table=pending_objects11062026/10/01 10:31:24 INFO Vacuumed table table=multipart_uploads11072026/10/01 10:31:25 INFO Vacuumed table table=closures11082026/10/01 10:31:25 INFO Vacuumed table table=objects1109--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.18s)1110=== CONT TestCacheStatsHandler11112026/10/01 10:31:25 INFO Received uploads request method=POST path=/api/pending_closures1112--- PASS: TestPushWaitsForSweepHoldingRow (2.63s)1113=== CONT TestClientIntegration11142026/10/01 10:31:25 INFO Received push request method=POST path=/api/pushes11152026/10/01 10:31:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11162026/10/01 10:31:25 INFO Uploading sgjnqb9sz73s7a91252g36ivb1spwrp4-a (248B)11172026/10/01 10:31:25 INFO Uploading wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9-shared-dep (136B)11182026/10/01 10:31:25 WARN Failed to register uploaded object key=nar/0lcpb7d6yz5dynnkx8mkz73dv57n1n2vva3xilhshnw6l8c7l7g6.nar.zst error="server returned 404: 404 page not found\n"11192026/10/01 10:31:25 WARN Failed to register uploaded object key=h4rcmxhl45ak1wkpf50pd91sq9czmv2l.ls error="server returned 404: 404 page not found\n"11202026/10/01 10:31:25 WARN Failed to register uploaded object key=sgjnqb9sz73s7a91252g36ivb1spwrp4.ls error="server returned 404: 404 page not found\n"11212026/10/01 10:31:25 WARN Failed to register uploaded object key=wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9.ls error="server returned 404: 404 page not found\n"11222026/10/01 10:31:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11232026/10/01 10:31:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11242026/10/01 10:31:25 INFO Signed narinfos id=1 count=311252026/10/01 10:31:25 INFO Uploading 3 narinfos11262026/10/01 10:31:25 WARN Failed to register uploaded object key=sgjnqb9sz73s7a91252g36ivb1spwrp4.narinfo error="server returned 404: 404 page not found\n"11272026/10/01 10:31:25 WARN Failed to register uploaded object key=h4rcmxhl45ak1wkpf50pd91sq9czmv2l.narinfo error="server returned 404: 404 page not found\n"11282026/10/01 10:31:25 INFO Received complete push request method=POST path=/api/pushes/1/complete11292026/10/01 10:31:25 WARN Failed to register uploaded object key=wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9.narinfo error="server returned 404: 404 page not found\n"11302026/10/01 10:31:25 INFO Upload complete. (116ms)1131=== NAME TestClientPushesUseOnePush1132 client_pushes_test.go:97: Retrieved narinfo from S3:1133 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientPushesUseOnePush3467917715/001/store/wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9-shared-dep1134 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1135 Compression: zstd1136 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821137 NarSize: 1361138 References: 1139 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1140 client_pushes_test.go:97: Retrieved narinfo from S3:1141 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientPushesUseOnePush3467917715/001/store/sgjnqb9sz73s7a91252g36ivb1spwrp4-a1142 URL: nar/0lcpb7d6yz5dynnkx8mkz73dv57n1n2vva3xilhshnw6l8c7l7g6.nar.zst1143 Compression: zstd1144 NarHash: sha256:0lcpb7d6yz5dynnkx8mkz73dv57n1n2vva3xilhshnw6l8c7l7g61145 NarSize: 2481146 References: /nix/var/nix/builds/nix-51998-174198025/TestClientPushesUseOnePush3467917715/001/store/wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9-shared-dep1147 CA: text:sha256:0ayk6g1ibfgd78xwgfppm2dh1k2m60vd3sav4lw0hrmal1p1ahry1148 client_pushes_test.go:97: Retrieved narinfo from S3:1149 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientPushesUseOnePush3467917715/001/store/h4rcmxhl45ak1wkpf50pd91sq9czmv2l-b1150 URL: nar/0lcpb7d6yz5dynnkx8mkz73dv57n1n2vva3xilhshnw6l8c7l7g6.nar.zst1151 Compression: zstd1152 NarHash: sha256:0lcpb7d6yz5dynnkx8mkz73dv57n1n2vva3xilhshnw6l8c7l7g61153 NarSize: 2481154 References: /nix/var/nix/builds/nix-51998-174198025/TestClientPushesUseOnePush3467917715/001/store/wg2wfpfl6fqsczqniz0k6v1qkb9g1aw9-shared-dep1155 CA: text:sha256:0ayk6g1ibfgd78xwgfppm2dh1k2m60vd3sav4lw0hrmal1p1ahry1156--- PASS: TestClientPushesUseOnePush (2.35s)1157=== CONT TestCacheConfigHandler1158=== RUN TestCacheConfigHandler/full_config,_no_issuer1159=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1160=== RUN TestCacheConfigHandler/no_cache_url_configured1161=== PAUSE TestCacheConfigHandler/no_cache_url_configured1162=== RUN TestCacheConfigHandler/no_signing_keys1163=== PAUSE TestCacheConfigHandler/no_signing_keys1164=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1165=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1166=== CONT TestClientErrorHandling1167=== RUN TestClientErrorHandling/InvalidStorePath1168=== PAUSE TestClientErrorHandling/InvalidStorePath1169=== RUN TestClientErrorHandling/InvalidAuthToken1170=== PAUSE TestClientErrorHandling/InvalidAuthToken1171=== RUN TestClientErrorHandling/ServerNotAvailable1172=== PAUSE TestClientErrorHandling/ServerNotAvailable1173=== CONT TestService_ReadScope_PublicByDefault1174=== NAME TestClientCADerivations1175 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-51998-174198025/TestClientCADerivations3950890969/001/store/svv2z1a7wvmd0hbsqna0c8mzyrrkx66p-ca-test1176 client_ca_test.go:139: Found 1 dependencies (including self)11772026/10/01 10:31:26 INFO Received push request method=POST path=/api/pushes11782026/10/01 10:31:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11792026/10/01 10:31:26 INFO Uploading svv2z1a7wvmd0hbsqna0c8mzyrrkx66p-ca-test (144B)11802026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11812026/10/01 10:31:26 WARN Failed to register uploaded object key=svv2z1a7wvmd0hbsqna0c8mzyrrkx66p.ls error="server returned 404: 404 page not found\n"11822026/10/01 10:31:26 WARN Failed to register uploaded object key=log/m1a05zkpa2l3ippycjds6ar40bcdyml0-ca-test.drv error="server returned 404: 404 page not found\n"11832026/10/01 10:31:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11842026/10/01 10:31:26 INFO Signed narinfos id=1 count=111852026/10/01 10:31:26 INFO Uploading 1 narinfos1186=== NAME TestPinProtectsFromGC1187 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-51998-174198025/TestPinProtectsFromGC4219725983/001/store/ik36a5q87a8xm7y78a5ih2mj1ih2dz9b-pinned-file.txt1188 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-51998-174198025/TestPinProtectsFromGC4219725983/001/store/hnfn58d48c4325rmszg5irgppdqnwjan-unpinned-file.txt11892026/10/01 10:31:26 INFO Received complete push request method=POST path=/api/pushes/1/complete11902026/10/01 10:31:26 WARN Failed to register uploaded object key=svv2z1a7wvmd0hbsqna0c8mzyrrkx66p.narinfo error="server returned 404: 404 page not found\n"11912026/10/01 10:31:26 INFO Upload complete. (153ms)1192=== NAME TestClientCADerivations1193 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientCADerivations3950890969/001/store/svv2z1a7wvmd0hbsqna0c8mzyrrkx66p-ca-test1194 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1195 Compression: zstd1196 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1197 NarSize: 1441198 References: 1199 Deriver: /nix/var/nix/builds/nix-51998-174198025/TestClientCADerivations3950890969/001/store/m1a05zkpa2l3ippycjds6ar40bcdyml0-ca-test.drv1200 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1201 client_ca_test.go:185: Checking for realisation files in S3...1202 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1203 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache12042026/10/01 10:31:26 INFO Received push request method=POST path=/api/pushes12052026/10/01 10:31:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12062026/10/01 10:31:26 INFO Uploading ik36a5q87a8xm7y78a5ih2mj1ih2dz9b-pinned-file.txt (128B)1207 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket46?endpoint=http://localhost:62838®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-51998-174198025/TestClientCADerivations3950890969/001/store'1208 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 112092026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12102026/10/01 10:31:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/01 10:31:26 WARN Failed to register uploaded object key=ik36a5q87a8xm7y78a5ih2mj1ih2dz9b.ls error="server returned 404: 404 page not found\n"12122026/10/01 10:31:26 INFO Signed narinfos id=1 count=112132026/10/01 10:31:26 INFO Uploading 1 narinfos12142026/10/01 10:31:26 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/10/01 10:31:26 WARN Failed to register uploaded object key=ik36a5q87a8xm7y78a5ih2mj1ih2dz9b.narinfo error="server returned 404: 404 page not found\n"12162026/10/01 10:31:26 INFO Upload complete. (139ms)1217--- PASS: TestClientCADerivations (2.85s)1218=== CONT TestPresignedUploadRegisteredBeforeCommit12192026/10/01 10:31:26 INFO Received push request method=POST path=/api/pushes12202026/10/01 10:31:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12212026/10/01 10:31:26 INFO Uploading hnfn58d48c4325rmszg5irgppdqnwjan-unpinned-file.txt (128B)12222026/10/01 10:31:26 WARN Failed to register uploaded object key=hnfn58d48c4325rmszg5irgppdqnwjan.ls error="server returned 404: 404 page not found\n"12232026/10/01 10:31:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12242026/10/01 10:31:26 INFO Signed narinfos id=2 count=112252026/10/01 10:31:26 INFO Uploading 1 narinfos12262026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12272026/10/01 10:31:26 INFO Received complete push request method=POST path=/api/pushes/2/complete12282026/10/01 10:31:26 WARN Failed to register uploaded object key=hnfn58d48c4325rmszg5irgppdqnwjan.narinfo error="server returned 404: 404 page not found\n"12292026/10/01 10:31:26 INFO Upload complete. (90ms)12302026/10/01 10:31:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures12312026/10/01 10:31:26 INFO Garbage collection started12322026/10/01 10:31:26 INFO Aborted multipart uploads count=0 kept=012332026/10/01 10:31:26 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/10/01 10:31:26 INFO Received push request method=POST path=/api/pushes12352026/10/01 10:31:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12362026/10/01 10:31:26 INFO Uploading svn3zj4hdplvvhf1wd5pcsq49bz1bm21-top (256B)12372026/10/01 10:31:26 INFO Uploading w7yaq1kj5l40dz4ag8xfyiy9zacn9ah2-shared-dep (136B)12382026/10/01 10:31:26 WARN Failed to register uploaded object key=svn3zj4hdplvvhf1wd5pcsq49bz1bm21.ls error="server returned 404: 404 page not found\n"12392026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12402026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/0k9qy8ibfgrxdd9wzsfkj2s3mkgj47lhf0x3r59nxmfsv84g05y1.nar.zst error="server returned 404: 404 page not found\n"12412026/10/01 10:31:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12422026/10/01 10:31:26 WARN Failed to register uploaded object key=w7yaq1kj5l40dz4ag8xfyiy9zacn9ah2.ls error="server returned 404: 404 page not found\n"12432026/10/01 10:31:26 INFO Signed narinfos id=1 count=212442026/10/01 10:31:26 INFO Uploading 2 narinfos12452026/10/01 10:31:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012462026/10/01 10:31:26 INFO Received complete push request method=POST path=/api/pushes/1/complete12472026/10/01 10:31:26 WARN Failed to register uploaded object key=w7yaq1kj5l40dz4ag8xfyiy9zacn9ah2.narinfo error="server returned 404: 404 page not found\n"12482026/10/01 10:31:26 WARN Failed to register uploaded object key=svn3zj4hdplvvhf1wd5pcsq49bz1bm21.narinfo error="server returned 404: 404 page not found\n"12492026/10/01 10:31:26 INFO Vacuumed table table=pending_closures12502026/10/01 10:31:26 INFO Upload complete. (120ms)1251=== NAME TestClientSharedPathCommittedMidPush1252 client_integration_test.go:680: Retrieved narinfo from S3:1253 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientSharedPathCommittedMidPush934963718/001/store/w7yaq1kj5l40dz4ag8xfyiy9zacn9ah2-shared-dep1254 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1255 Compression: zstd1256 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821257 NarSize: 1361258 References: 1259 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1260 client_integration_test.go:680: Retrieved narinfo from S3:1261 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientSharedPathCommittedMidPush934963718/001/store/svn3zj4hdplvvhf1wd5pcsq49bz1bm21-top1262 URL: nar/0k9qy8ibfgrxdd9wzsfkj2s3mkgj47lhf0x3r59nxmfsv84g05y1.nar.zst1263 Compression: zstd1264 NarHash: sha256:0k9qy8ibfgrxdd9wzsfkj2s3mkgj47lhf0x3r59nxmfsv84g05y11265 NarSize: 2561266 References: /nix/var/nix/builds/nix-51998-174198025/TestClientSharedPathCommittedMidPush934963718/001/store/w7yaq1kj5l40dz4ag8xfyiy9zacn9ah2-shared-dep1267 CA: text:sha256:0xl863393q65iz8v61sk3wmap5ayl2fnkmkyl9bqimi1l3zrlgfm12682026/10/01 10:31:26 INFO Vacuumed table table=pending_objects12692026/10/01 10:31:26 INFO Vacuumed table table=multipart_uploads12702026/10/01 10:31:26 INFO Vacuumed table table=closures1271=== RUN TestService_RequireScope_OIDC/builder_may_write1272=== PAUSE TestService_RequireScope_OIDC/builder_may_write1273=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1274=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1275=== RUN TestService_RequireScope_OIDC/ops_may_admin1276=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1277=== RUN TestService_RequireScope_OIDC/ops_may_not_write1278=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1279=== RUN TestService_RequireScope_OIDC/reader_may_not_write1280=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1281=== RUN TestService_RequireScope_OIDC/static_token_may_admin1282=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1283=== RUN TestService_RequireScope_OIDC/static_token_may_write1284=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1285=== RUN TestService_RequireScope_OIDC/reader_may_read1286=== PAUSE TestService_RequireScope_OIDC/reader_may_read1287=== RUN TestService_RequireScope_OIDC/writer_implies_read1288=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1289=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1290=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1291=== CONT TestPush_CompleteCommitsEveryRoot1292--- PASS: TestClientSharedPathCommittedMidPush (2.60s)1293=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12942026/10/01 10:31:26 INFO Vacuumed table table=objects1295--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.84s)1296=== CONT TestCompleteMultipartUnregistered1297=== NAME TestClientWithDependencies1298 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-51998-174198025/TestClientWithDependencies2717714089/001/store/7l12jn4b1ya8x5rq0a1k9b11xkxyvb93-test-script1299 client_integration_test.go:615: Found 1 dependencies (including self)13002026/10/01 10:31:26 INFO Received push request method=POST path=/api/pushes13012026/10/01 10:31:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13022026/10/01 10:31:26 INFO Uploading 7l12jn4b1ya8x5rq0a1k9b11xkxyvb93-test-script (136B)13032026/10/01 10:31:26 WARN Failed to register uploaded object key=7l12jn4b1ya8x5rq0a1k9b11xkxyvb93.ls error="server returned 404: 404 page not found\n"13042026/10/01 10:31:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13052026/10/01 10:31:26 WARN Failed to register uploaded object key=log/a3wqwqiangag7lvakv278gqp6rwqwi58-test-script.drv error="server returned 404: 404 page not found\n"13062026/10/01 10:31:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13072026/10/01 10:31:26 INFO Signed narinfos id=1 count=113082026/10/01 10:31:26 INFO Uploading 1 narinfos13092026/10/01 10:31:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13102026/10/01 10:31:26 WARN Failed to register uploaded object key=7l12jn4b1ya8x5rq0a1k9b11xkxyvb93.narinfo error="server returned 404: 404 page not found\n"13112026/10/01 10:31:26 INFO Upload complete. (139ms)1312 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-51998-174198025/TestClientWithDependencies2717714089/001/store) requires matching store prefix1313=== NAME TestClientMultipleUploads1314 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-51998-174198025/TestClientMultipleUploads2894587969/001/store/b079n62r31qfq0g9b3llarq6saksmb28-test-file-0.txt1315--- PASS: TestClientWithDependencies (2.70s)1316=== CONT TestCompletedNarNotReofferedAcrossClosures1317--- PASS: TestCacheStatsHandler (2.05s)1318=== CONT TestService_verifyS3Integrity1319=== NAME TestClientMultipleUploads1320 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-51998-174198025/TestClientMultipleUploads2894587969/001/store/bf3n2b5k4c8lz93w9sp4n3dxg1410zma-test-file-1.txt1321 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-51998-174198025/TestClientMultipleUploads2894587969/001/store/dn324rf73ggbx7pjf3khgqvdckddrrig-test-file-2.txt13222026/10/01 10:31:27 INFO Received push request method=POST path=/api/pushes13232026/10/01 10:31:27 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13242026/10/01 10:31:27 INFO Uploading dn324rf73ggbx7pjf3khgqvdckddrrig-test-file-2.txt (160B)13252026/10/01 10:31:27 INFO Uploading bf3n2b5k4c8lz93w9sp4n3dxg1410zma-test-file-1.txt (160B)13262026/10/01 10:31:27 INFO Uploading b079n62r31qfq0g9b3llarq6saksmb28-test-file-0.txt (160B)13272026/10/01 10:31:27 WARN Failed to register uploaded object key=b079n62r31qfq0g9b3llarq6saksmb28.ls error="server returned 404: 404 page not found\n"13282026/10/01 10:31:27 WARN Failed to register uploaded object key=dn324rf73ggbx7pjf3khgqvdckddrrig.ls error="server returned 404: 404 page not found\n"13292026/10/01 10:31:27 WARN Failed to register uploaded object key=bf3n2b5k4c8lz93w9sp4n3dxg1410zma.ls error="server returned 404: 404 page not found\n"13302026/10/01 10:31:27 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13312026/10/01 10:31:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13322026/10/01 10:31:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13332026/10/01 10:31:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13342026/10/01 10:31:27 INFO Signed narinfos id=1 count=313352026/10/01 10:31:27 INFO Uploading 3 narinfos13362026/10/01 10:31:27 WARN Failed to register uploaded object key=b079n62r31qfq0g9b3llarq6saksmb28.narinfo error="server returned 404: 404 page not found\n"13372026/10/01 10:31:27 INFO Received complete push request method=POST path=/api/pushes/1/complete13382026/10/01 10:31:27 WARN Failed to register uploaded object key=dn324rf73ggbx7pjf3khgqvdckddrrig.narinfo error="server returned 404: 404 page not found\n"13392026/10/01 10:31:27 WARN Failed to register uploaded object key=bf3n2b5k4c8lz93w9sp4n3dxg1410zma.narinfo error="server returned 404: 404 page not found\n"13402026/10/01 10:31:27 INFO Upload complete. (158ms)1341 client_integration_test.go:369: Uploaded 3 paths in 194.315541ms1342=== NAME TestClientIntegration1343 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-51998-174198025/TestClientIntegration488512777/002/store/gdd4mp2yq8v5cc3clnx0vbjaqjcxg5sf-test-file.txt1344--- PASS: TestClientMultipleUploads (2.84s)1345=== CONT TestService_createPendingClosureHandler1346--- PASS: TestService_ReadScope_PublicByDefault (1.59s)1347=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13482026/10/01 10:31:27 INFO Received push request method=POST path=/api/pushes13492026/10/01 10:31:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13502026/10/01 10:31:27 INFO Uploading gdd4mp2yq8v5cc3clnx0vbjaqjcxg5sf-test-file.txt (152B)13512026/10/01 10:31:27 WARN Failed to register uploaded object key=gdd4mp2yq8v5cc3clnx0vbjaqjcxg5sf.ls error="server returned 404: 404 page not found\n"13522026/10/01 10:31:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13532026/10/01 10:31:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13542026/10/01 10:31:27 INFO Signed narinfos id=1 count=113552026/10/01 10:31:27 INFO Uploading 1 narinfos13562026/10/01 10:31:27 INFO Received complete push request method=POST path=/api/pushes/1/complete13572026/10/01 10:31:27 WARN Failed to register uploaded object key=gdd4mp2yq8v5cc3clnx0vbjaqjcxg5sf.narinfo error="server returned 404: 404 page not found\n"13582026/10/01 10:31:27 INFO Upload complete. (89ms)13592026/10/01 10:31:27 INFO All 1 paths already cached1360=== NAME TestClientIntegration1361 client_integration_test.go:312: Retrieved narinfo from S3:1362 StorePath: /nix/var/nix/builds/nix-51998-174198025/TestClientIntegration488512777/002/store/gdd4mp2yq8v5cc3clnx0vbjaqjcxg5sf-test-file.txt1363 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1364 Compression: zstd1365 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11366 NarSize: 1521367 References: 1368 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11369 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1370 client_integration_test.go:313: Decompressed .ls content (64 bytes):1371 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1372 client_integration_test.go:316: Testing garbage collection...13732026/10/01 10:31:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures13742026/10/01 10:31:27 INFO Garbage collection started13752026/10/01 10:31:27 INFO Aborted multipart uploads count=0 kept=013762026/10/01 10:31:27 WARN Force mode enabled - objects will be deleted immediately without grace period13772026/10/01 10:31:27 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=013782026/10/01 10:31:27 INFO Vacuumed table table=pending_closures13792026/10/01 10:31:27 INFO Vacuumed table table=pending_objects13802026/10/01 10:31:27 INFO Vacuumed table table=multipart_uploads13812026/10/01 10:31:27 INFO Vacuumed table table=closures13822026/10/01 10:31:27 INFO Vacuumed table table=objects13832026/10/01 10:31:27 INFO Received uploads request method=POST path=/api/pending_closures13842026/10/01 10:31:27 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13852026/10/01 10:31:27 INFO Received uploads request method=POST path=/api/pending_closures1386--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.55s)1387=== CONT TestService_cleanupPendingClosuresHandler13882026/10/01 10:31:28 INFO Received push request method=POST path=/api/pushes13892026/10/01 10:31:28 INFO Received complete push request method=POST path=/api/pushes/1/complete1390--- PASS: TestPush_CompleteCommitsEveryRoot (1.56s)1391=== CONT TestUploadHandlersRejectOversizedBody1392=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1393=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1394=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1395=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1396=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1397=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1398=== CONT TestRedundantMultipartUpload13992026/10/01 10:31:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14002026/10/01 10:31:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1401--- PASS: TestCompleteMultipartUnregistered (1.62s)1402=== CONT TestUploadHandlersRejectInvalidKeys1403=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1404=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1405=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1406=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1407=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1408=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1409=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1410=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1411=== CONT TestIsValidUploadKey1412=== RUN TestIsValidUploadKey/narinfo1413=== PAUSE TestIsValidUploadKey/narinfo1414=== RUN TestIsValidUploadKey/nar_zst1415=== PAUSE TestIsValidUploadKey/nar_zst1416=== RUN TestIsValidUploadKey/nar_xz1417=== PAUSE TestIsValidUploadKey/nar_xz1418=== RUN TestIsValidUploadKey/nar_plain1419=== PAUSE TestIsValidUploadKey/nar_plain1420=== RUN TestIsValidUploadKey/listing1421=== PAUSE TestIsValidUploadKey/listing1422=== RUN TestIsValidUploadKey/build_log1423=== PAUSE TestIsValidUploadKey/build_log1424=== RUN TestIsValidUploadKey/build_log_home-manager_file1425=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1426=== RUN TestIsValidUploadKey/build_log_plus_in_name1427=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1428=== RUN TestIsValidUploadKey/build_log_question_mark1429=== PAUSE TestIsValidUploadKey/build_log_question_mark1430=== RUN TestIsValidUploadKey/build_log_equals1431=== PAUSE TestIsValidUploadKey/build_log_equals1432=== RUN TestIsValidUploadKey/realisation1433=== PAUSE TestIsValidUploadKey/realisation1434=== RUN TestIsValidUploadKey/realisation_plus_in_output1435=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1436=== RUN TestIsValidUploadKey/nix-cache-info1437=== PAUSE TestIsValidUploadKey/nix-cache-info1438=== RUN TestIsValidUploadKey/index.html1439=== PAUSE TestIsValidUploadKey/index.html1440=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1441=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1442=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1443=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1444=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1445=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1446=== RUN TestIsValidUploadKey/traversal1447=== PAUSE TestIsValidUploadKey/traversal1448=== RUN TestIsValidUploadKey/traversal_nar1449=== PAUSE TestIsValidUploadKey/traversal_nar1450=== RUN TestIsValidUploadKey/absolute1451=== PAUSE TestIsValidUploadKey/absolute1452=== RUN TestIsValidUploadKey/empty_key1453=== PAUSE TestIsValidUploadKey/empty_key1454=== RUN TestIsValidUploadKey/unknown_type1455=== PAUSE TestIsValidUploadKey/unknown_type1456=== CONT TestPush_SignsNarinfosOfItsPendingObjects14572026/10/01 10:31:28 INFO Received uploads request method=POST path=/api/pending_closures14582026/10/01 10:31:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=014592026/10/01 10:31:28 INFO Received create pin request method=POST path=/api/pins/myapp1460--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.90s)1461=== CONT TestPendingClosureWriteTimeout1462=== RUN TestPendingClosureWriteTimeout/empty1463=== PAUSE TestPendingClosureWriteTimeout/empty1464=== RUN TestPendingClosureWriteTimeout/400_objects1465=== PAUSE TestPendingClosureWriteTimeout/400_objects1466=== RUN TestPendingClosureWriteTimeout/670k_objects1467=== PAUSE TestPendingClosureWriteTimeout/670k_objects1468=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1469=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1470=== CONT TestProxyWriteTimeout1471=== RUN TestProxyWriteTimeout/narinfo1472=== PAUSE TestProxyWriteTimeout/narinfo1473=== RUN TestProxyWriteTimeout/1_GiB_nar1474=== PAUSE TestProxyWriteTimeout/1_GiB_nar1475=== RUN TestProxyWriteTimeout/10_GiB_nar1476=== PAUSE TestProxyWriteTimeout/10_GiB_nar1477=== RUN TestProxyWriteTimeout/unknown_size1478=== PAUSE TestProxyWriteTimeout/unknown_size1479=== CONT TestPush_RejectsBadRequests14802026/10/01 10:31:28 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-51998-174198025/TestPinProtectsFromGC4219725983/001/store/ik36a5q87a8xm7y78a5ih2mj1ih2dz9b-pinned-file.txt narinfo_key=ik36a5q87a8xm7y78a5ih2mj1ih2dz9b.narinfo14812026/10/01 10:31:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures14822026/10/01 10:31:28 INFO Garbage collection started14832026/10/01 10:31:28 INFO Aborted multipart uploads count=0 kept=014842026/10/01 10:31:28 WARN Force mode enabled - objects will be deleted immediately without grace period14852026/10/01 10:31:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014862026/10/01 10:31:28 INFO Vacuumed table table=pending_closures14872026/10/01 10:31:28 INFO Vacuumed table table=pending_objects14882026/10/01 10:31:28 INFO Vacuumed table table=multipart_uploads14892026/10/01 10:31:28 INFO Vacuumed table table=closures14902026/10/01 10:31:28 INFO Vacuumed table table=objects14912026/10/01 10:31:28 INFO Received uploads request method=POST path=/api/pending_closures14922026/10/01 10:31:28 INFO Received uploads request method=POST path=/api/pending_closures14932026/10/01 10:31:29 INFO Received uploads request method=POST path=/api/pending_closures14942026/10/01 10:31:29 INFO Received uploads request method=POST path=/api/pending_closures14952026/10/01 10:31:29 INFO Received uploads request method=POST path=/api/pending_closures14962026/10/01 10:31:29 INFO Received uploads request method=POST path=/api/pending_closures14972026/10/01 10:31:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=014982026/10/01 10:31:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1499=== NAME TestClientIntegration1500 client_integration_test.go:323: Objects in database after GC:1501 client_integration_test.go:323: Successfully deleted all objects with GC --force15022026/10/01 10:31:29 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjQ4ZTZkZWFjLTUyNGQtNDE4ZC1hN2YxLWZkMGJjNjgwNmQ2OHgxNzkwODUwNjg5MzA5NjYzMDAw15032026/10/01 10:31:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjQ4ZTZkZWFjLTUyNGQtNDE4ZC1hN2YxLWZkMGJjNjgwNmQ2OHgxNzkwODUwNjg5MzA5NjYzMDAw parts=11504--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.21s)1505=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1506--- PASS: TestClientIntegration (4.13s)1507=== CONT TestSkippedUploadsHandler15082026/10/01 10:31:29 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001509--- PASS: TestSkippedUploadsHandler (0.00s)1510=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15112026/10/01 10:31:30 INFO Received cleanup request method=DELETE path=/api/pending_closures15122026/10/01 10:31:30 INFO Aborted multipart uploads count=0 kept=015132026/10/01 10:31:30 INFO Received uploads request method=POST path=/api/pending_closures15142026/10/01 10:31:30 INFO Received cleanup request method=DELETE path=/api/pending_closures15152026/10/01 10:31:30 INFO Aborted multipart uploads count=1 kept=015162026/10/01 10:31:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15172026-10-01 10:31:30.271 UTC [52419] ERROR: Closure does not exist: id=115182026-10-01 10:31:30.271 UTC [52419] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15192026-10-01 10:31:30.271 UTC [52419] STATEMENT: -- name: CommitPendingClosure :exec1520 SELECT commit_pending_closure($1::bigint)1521 15222026/10/01 10:31:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1523--- PASS: TestService_cleanupPendingClosuresHandler (2.41s)1524=== CONT TestParseSize1525--- PASS: TestParseSize (0.00s)1526=== CONT TestService_Rustfstest15272026/10/01 10:31:30 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjdmMTYzYjQ5LWI5ZmQtNDkyOS1iYjc5LWJmNzA0M2ExOTAxZHgxNzkwODUwNjg4NzAyNjU0MDAw parts=1015282026/10/01 10:31:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15292026/10/01 10:31:30 INFO Completed upload id=115302026/10/01 10:31:30 INFO Received uploads request method=POST path=/api/pending_closures15312026/10/01 10:31:30 INFO Received uploads request method=POST path=/api/pending_closures15322026/10/01 10:31:30 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15332026/10/01 10:31:30 WARN Found objects in DB but missing from S3, will re-upload count=11534--- PASS: TestService_verifyS3Integrity (3.31s)1535=== CONT TestReadRedirectKeepsNarinfoProxied1536=== NAME TestPinProtectsFromGC1537 client_integration_test.go:840: Pin successfully protected closure from garbage collection1538--- PASS: TestPinProtectsFromGC (6.76s)1539=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15402026/10/01 10:31:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15412026/10/01 10:31:30 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjM4ZTIyOTdkLWQ1MDYtNGY3ZC1hZDRmLWVlYmU3YzkzMDdkYngxNzkwODUwNjg4OTYyODkxMDAw parts=1215422026/10/01 10:31:30 INFO Received uploads request method=POST path=/api/pending_closures1543--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.81s)1544=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15452026/10/01 10:31:30 INFO Received push request method=POST path=/api/pushes15462026/10/01 10:31:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15472026/10/01 10:31:30 INFO Signed narinfos id=1 count=11548--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.69s)1549=== CONT TestService_AuthMiddleware_OIDC15502026/10/01 10:31:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63159/oidc15512026/10/01 10:31:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15522026/10/01 10:31:31 INFO Received uploads request method=POST path=/api/pending_closures15532026/10/01 10:31:31 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2Ljk3ZWRmNWE3LTJjYTQtNGQ4Mi1hOWY2LTgwN2E2MTkwZDRhNngxNzkwODUwNjg5NjIyNzg3MDAw parts=1015542026/10/01 10:31:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15552026/10/01 10:31:31 INFO Completed upload id=115562026/10/01 10:31:31 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015572026/10/01 10:31:31 INFO Received uploads request method=POST path=/api/pending_closures15582026/10/01 10:31:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures15592026/10/01 10:31:31 INFO Aborted multipart uploads count=0 kept=015602026/10/01 10:31:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015612026/10/01 10:31:31 INFO Vacuumed table table=pending_closures15622026/10/01 10:31:31 INFO Received uploads request method=POST path=/api/pending_closures15632026/10/01 10:31:31 INFO Vacuumed table table=pending_objects15642026/10/01 10:31:31 INFO Vacuumed table table=multipart_uploads15652026/10/01 10:31:31 INFO Vacuumed table table=closures15662026/10/01 10:31:31 INFO Vacuumed table table=objects15672026/10/01 10:31:31 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001568--- PASS: TestService_createPendingClosureHandler (3.93s)1569=== CONT TestReadRedirectUsesPublicS3URL1570=== RUN TestPush_RejectsBadRequests/no_objects1571=== PAUSE TestPush_RejectsBadRequests/no_objects1572=== RUN TestPush_RejectsBadRequests/bad_root1573=== PAUSE TestPush_RejectsBadRequests/bad_root1574=== RUN TestPush_RejectsBadRequests/root_not_in_objects1575=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1576=== RUN TestPush_RejectsBadRequests/no_roots1577=== PAUSE TestPush_RejectsBadRequests/no_roots1578=== CONT TestService_ReadAuthMiddleware15792026/10/01 10:31:31 INFO Received push request method=POST path=/api/pushes15802026/10/01 10:31:31 INFO Received complete push request method=POST path=/api/pushes/1/complete15812026/10/01 10:31:32 INFO Received push request method=POST path=/api/pushes15822026/10/01 10:31:32 INFO Aborted multipart uploads count=0 kept=015832026/10/01 10:31:32 WARN Force mode enabled - objects will be deleted immediately without grace period15842026/10/01 10:31:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=015852026/10/01 10:31:32 INFO Vacuumed table table=pending_closures15862026/10/01 10:31:32 INFO Vacuumed table table=pending_objects15872026/10/01 10:31:32 INFO Received uploads request method=POST path=/api/pending_closures15882026/10/01 10:31:32 INFO Vacuumed table table=multipart_uploads15892026/10/01 10:31:32 INFO Vacuumed table table=closures15902026/10/01 10:31:32 INFO Vacuumed table table=objects15912026/10/01 10:31:32 INFO Received complete push request method=POST path=/api/pushes/2/complete1592--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.58s)1593=== CONT TestService_AuthMiddleware_MTLSProxyHeader15942026/10/01 10:31:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15952026/10/01 10:31:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1596--- PASS: TestService_Rustfstest (2.46s)1597=== CONT TestReadProxyRangeRequest15982026/10/01 10:31:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjhmMjBkMDljLTA0ZTItNDM2ZC05OTIxLTY3NmU2MjRlOGFmNXgxNzkwODUwNjkxMTU1MjMxMDAw parts=1215992026/10/01 10:31:32 INFO Received uploads request method=POST path=/api/pending_closures16002026/10/01 10:31:32 INFO Received uploads request method=POST path=/api/pending_closures1601--- PASS: TestReadRedirectKeepsNarinfoProxied (2.69s)1602=== CONT TestReadProxyDisabled16032026/10/01 10:31:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16042026/10/01 10:31:33 WARN mTLS auth: bound subjects configured but subject DN unavailable16052026/10/01 10:31:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1606--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.82s)1607=== CONT TestReadProxyRootRedirectsToIndexHTML16082026/10/01 10:31:33 INFO Received push request method=POST path=/api/pushes1609--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.89s)1610=== CONT TestReadRedirectNar1611=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1612=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1613=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1614=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1615=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1616=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1617=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1618=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1619=== CONT TestIsValidCachePath/narinfo1620=== CONT TestIsValidCachePath/index.html1621=== CONT TestIsValidCachePath/nix-cache-info1622=== CONT TestIsValidCachePath/realisation1623=== CONT TestIsValidCachePath/log1624=== CONT TestIsValidCachePath/ls1625=== CONT TestIsValidCachePath/nar_uncompressed1626=== CONT TestIsValidCachePath/nar_bz21627=== CONT TestIsValidCachePath/nar_xz1628=== CONT TestIsValidCachePath/nar_zst1629=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1630=== CONT TestIsValidCachePath/empty1631=== CONT TestIsValidCachePath/traversal_parent1632=== CONT TestIsValidCachePath/random_path1633=== CONT TestIsValidCachePath/invalid_char_u1634=== CONT TestIsValidCachePath/invalid_char_e1635=== CONT TestIsValidCachePath/traversal_in_middle1636=== CONT TestIsValidCachePath/wrong_extension1637=== CONT TestIsValidCachePath/short_hash1638=== CONT TestIsValidCachePath/leading_slash1639--- PASS: TestIsValidCachePath (0.00s)1640 --- PASS: TestIsValidCachePath/narinfo (0.00s)1641 --- PASS: TestIsValidCachePath/index.html (0.00s)1642 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1643 --- PASS: TestIsValidCachePath/realisation (0.00s)1644 --- PASS: TestIsValidCachePath/log (0.00s)1645 --- PASS: TestIsValidCachePath/ls (0.00s)1646 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1647 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1648 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1649 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1650 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1651 --- PASS: TestIsValidCachePath/empty (0.00s)1652 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1653 --- PASS: TestIsValidCachePath/random_path (0.00s)1654 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1655 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1656 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1657 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1658 --- PASS: TestIsValidCachePath/short_hash (0.00s)1659 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1660=== CONT TestParseSingleRange/none1661=== CONT TestParseSingleRange/single_byte1662=== CONT TestParseSingleRange/suffix_exceeds_size1663=== CONT TestParseSingleRange/suffix1664=== CONT TestParseSingleRange/end_clamped_to_size1665=== CONT TestParseSingleRange/open-ended1666=== CONT TestParseSingleRange/closed1667=== CONT TestParseSingleRange/malformed_end_before_start1668=== CONT TestParseSingleRange/malformed_both_empty1669=== CONT TestParseSingleRange/malformed_no_dash1670=== CONT TestParseSingleRange/multi-range_ignored1671=== CONT TestParseSingleRange/unknown_unit1672=== CONT TestParseSingleRange/start_past_EOF1673=== CONT TestParseSingleRange/start_far_past_EOF1674--- PASS: TestParseSingleRange (0.00s)1675 --- PASS: TestParseSingleRange/none (0.00s)1676 --- PASS: TestParseSingleRange/single_byte (0.00s)1677 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1678 --- PASS: TestParseSingleRange/suffix (0.00s)1679 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1680 --- PASS: TestParseSingleRange/open-ended (0.00s)1681 --- PASS: TestParseSingleRange/closed (0.00s)1682 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1683 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1684 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1685 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1686 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1687 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1688 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1689=== CONT TestServerTLSConfig/no_client_CA1690=== CONT TestServerTLSConfig/not_a_PEM_file1691=== CONT TestServerTLSConfig/missing_CA_file1692--- PASS: TestServerTLSConfig (0.00s)1693 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1694 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1695 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1696=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1697--- PASS: TestReadRedirectUsesPublicS3URL (3.03s)1698=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16992026/10/01 10:31:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1700--- PASS: TestService_ReadAuthMiddleware (3.34s)1701=== CONT TestResolveDBConnectionString/flag_wins1702=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1703=== CONT TestResolveDBConnectionString/nothing_configured1704=== CONT TestResolveDBConnectionString/missing_file_is_an_error1705=== CONT TestResolveDBConnectionString/file_when_flag_empty1706=== CONT TestCacheConfigHandler/full_config,_no_issuer1707=== CONT TestCacheConfigHandler/no_signing_keys1708=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1709=== CONT TestCacheConfigHandler/no_cache_url_configured1710--- PASS: TestCacheConfigHandler (0.00s)1711 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1712 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1713 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1714 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1715=== CONT TestClientErrorHandling/InvalidStorePath1716--- PASS: TestResolveDBConnectionString (0.04s)1717 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1718 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1719 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1720 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1721 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17222026/10/01 10:31:34 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjEyZjA4ODQ2LTE3YWEtNGMxOS04ZWI1LThjZmJkOWZmMzkwMHgxNzkwODUwNjkyODAyNDk3MDAw error="Get \"http://127.0.0.1:1/bucket67/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17232026/10/01 10:31:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmI3ZGI2YmMtNWE4Ni00NTgzLTg4NDgtMDM3ZGIwMzFhNDI2LjQxNjMxODVlLTFiMDItNDZhYy1hZjk0LWIyMzVkOTI0NDVkMngxNzkwODUwNjkyNzU2MzU1MDAw parts=1217242026/10/01 10:31:34 INFO Received cleanup request method=DELETE path=/api/pending_closures17252026/10/01 10:31:34 INFO Aborted multipart uploads count=1 kept=01726--- PASS: TestRedundantMultipartUpload (6.64s)1727=== CONT TestClientErrorHandling/InvalidAuthToken1728--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.03s)1729=== CONT TestClientErrorHandling/ServerNotAvailable1730--- PASS: TestReadProxyRangeRequest (2.91s)1731=== CONT TestService_RequireScope_OIDC/builder_may_write1732=== CONT TestService_RequireScope_OIDC/static_token_may_admin1733=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1734=== CONT TestService_RequireScope_OIDC/writer_implies_read1735=== CONT TestService_RequireScope_OIDC/reader_may_read1736=== CONT TestService_RequireScope_OIDC/static_token_may_write1737=== CONT TestService_RequireScope_OIDC/ops_may_not_write1738=== CONT TestService_RequireScope_OIDC/reader_may_not_write1739=== CONT TestService_RequireScope_OIDC/ops_may_admin1740=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1741=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17422026/10/01 10:31:35 INFO Received uploads request method=POST path=/1743--- PASS: TestService_RequireScope_OIDC (2.31s)1744 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1745 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1746 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1747 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1748 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1749 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1750 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1751 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1752 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1753 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)17542026/10/01 10:31:35 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/present17552026/10/01 10:31:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.528875ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1756--- PASS: TestReadProxyDisabled (2.81s)1757=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17582026/10/01 10:31:35 INFO Received complete multipart upload request method=POST path=/1759=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17602026/10/01 10:31:35 INFO Received request for more parts method=POST path=/1761=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17622026/10/01 10:31:35 INFO Received uploads request method=POST path=/1763=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17642026/10/01 10:31:35 INFO Received complete multipart upload request method=POST path=/1765=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17662026/10/01 10:31:35 INFO Received request for more parts method=POST path=/1767=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17682026/10/01 10:31:35 INFO Received uploads request method=POST path=/1769--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1770 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1771 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1772 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1773 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1774=== CONT TestIsValidUploadKey/narinfo1775=== CONT TestIsValidUploadKey/realisation_plus_in_output1776=== CONT TestIsValidUploadKey/unknown_type1777=== CONT TestIsValidUploadKey/empty_key1778=== CONT TestIsValidUploadKey/absolute1779=== CONT TestIsValidUploadKey/traversal_nar1780=== CONT TestIsValidUploadKey/traversal1781=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1782=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1783=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1784=== CONT TestIsValidUploadKey/index.html1785=== CONT TestIsValidUploadKey/nix-cache-info1786=== CONT TestIsValidUploadKey/build_log_home-manager_file1787=== CONT TestIsValidUploadKey/realisation1788=== CONT TestIsValidUploadKey/build_log_equals1789=== CONT TestIsValidUploadKey/build_log_question_mark1790=== CONT TestIsValidUploadKey/build_log_plus_in_name1791=== CONT TestIsValidUploadKey/nar_xz1792=== CONT TestIsValidUploadKey/nar_zst1793=== CONT TestIsValidUploadKey/nar_plain1794=== CONT TestIsValidUploadKey/build_log1795=== CONT TestIsValidUploadKey/listing1796--- PASS: TestIsValidUploadKey (0.00s)1797 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1798 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1799 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1800 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1801 --- PASS: TestIsValidUploadKey/absolute (0.00s)1802 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1803 --- PASS: TestIsValidUploadKey/traversal (0.00s)1804 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1805 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1806 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1807 --- PASS: TestIsValidUploadKey/index.html (0.00s)1808 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1809 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1810 --- PASS: TestIsValidUploadKey/realisation (0.00s)1811 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1813 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1814 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1815 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1816 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1817 --- PASS: TestIsValidUploadKey/build_log (0.00s)1818 --- PASS: TestIsValidUploadKey/listing (0.00s)1819=== CONT TestPendingClosureWriteTimeout/empty1820=== CONT TestProxyWriteTimeout/narinfo1821=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1822--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1823 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1824 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1825 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1826=== CONT TestPendingClosureWriteTimeout/670k_objects1827=== CONT TestPendingClosureWriteTimeout/400_objects1828=== CONT TestProxyWriteTimeout/10_GiB_nar1829=== CONT TestProxyWriteTimeout/unknown_size1830=== CONT TestProxyWriteTimeout/1_GiB_nar1831--- PASS: TestProxyWriteTimeout (0.00s)1832 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1833 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1834 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1835 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1836=== CONT TestPush_RejectsBadRequests/no_objects18372026/10/01 10:31:35 INFO Received push request method=POST path=/api/pushes1838=== CONT TestPush_RejectsBadRequests/root_not_in_objects18392026/10/01 10:31:35 INFO Received push request method=POST path=/api/pushes1840=== CONT TestPush_RejectsBadRequests/no_roots18412026/10/01 10:31:35 INFO Received push request method=POST path=/api/pushes1842=== CONT TestPush_RejectsBadRequests/bad_root18432026/10/01 10:31:35 INFO Received push request method=POST path=/api/pushes1844=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1845--- PASS: TestPush_RejectsBadRequests (2.87s)1846 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1847 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1848 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1849 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1850=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1851=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18522026/10/01 10:31:35 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]1853=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18542026/10/01 10:31:35 WARN Authentication failed token_preview=eyJhbGciOi...TupHgJflcA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1855--- PASS: TestService_AuthMiddleware_OIDC (3.05s)1856 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1857 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1858 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1859 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18602026/10/01 10:31:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.402268ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1861--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.81s)18622026/10/01 10:31:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.753196ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1863--- PASS: TestReadRedirectNar (2.76s)18642026/10/01 10:31:36 INFO Received uploads request method=POST path=/api/pending_closures18652026/10/01 10:31:36 INFO Aborted multipart uploads count=0 kept=018662026/10/01 10:31:36 WARN Force mode enabled - objects will be deleted immediately without grace period18672026/10/01 10:31:36 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=018682026/10/01 10:31:36 INFO Vacuumed table table=pending_closures18692026/10/01 10:31:36 INFO Vacuumed table table=pending_objects18702026/10/01 10:31:36 INFO Vacuumed table table=multipart_uploads18712026/10/01 10:31:36 INFO Vacuumed table table=closures18722026/10/01 10:31:36 INFO Vacuumed table table=objects18732026/10/01 10:31:37 INFO Received uploads request method=POST path=/api/pending_closures18742026/10/01 10:31:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44728722s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18752026/10/01 10:31:37 INFO Aborted multipart uploads count=0 kept=018762026/10/01 10:31:37 WARN Force mode enabled - objects will be deleted immediately without grace period18772026/10/01 10:31:37 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=018782026/10/01 10:31:37 INFO Vacuumed table table=pending_closures18792026/10/01 10:31:37 INFO Vacuumed table table=pending_objects18802026/10/01 10:31:37 INFO Vacuumed table table=multipart_uploads18812026/10/01 10:31:37 INFO Vacuumed table table=closures18822026/10/01 10:31:37 INFO Vacuumed table table=objects18832026/10/01 10:31:37 WARN Rate limiter enabled after throttle name=s3-test rate=518842026/10/01 10:31:37 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1885=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1886 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101887 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001888--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.72s)1889--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1890 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.08s)1891 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.98s)18922026/10/01 10:31:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18932026/10/01 10:31:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18942026/10/01 10:31:37 INFO Received uploads request method=POST path=/api/pending_closures1895--- PASS: TestPendingClosureWriteTimeout (0.00s)1896 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1897 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1898 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1899 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.79s)19002026/10/01 10:31:38 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-config19012026/10/01 10:31:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.544275ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19022026/10/01 10:31:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.479955ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19032026/10/01 10:31:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.750503ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19042026/10/01 10:31:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.672071075s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19052026/10/01 10:31:41 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"19062026/10/01 10:31:41 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-config19072026/10/01 10:31:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.734765ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/10/01 10:31:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.47258ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19092026/10/01 10:31:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=851.48703ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19102026/10/01 10:31:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.75212436s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19112026/10/01 10:31:45 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_closures19122026/10/01 10:31:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.112655ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19132026/10/01 10:31:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.733599ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19142026/10/01 10:31:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=807.747122ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19152026/10/01 10:31:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.702511039s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1916--- PASS: TestClientErrorHandling (0.00s)1917 --- PASS: TestClientErrorHandling/InvalidStorePath (2.98s)1918 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.86s)1919 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.06s)1920PASS1921{"timestamp":"2026-10-01T10:31:48.373171Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63152","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)"}19222026-10-01 10:31:48.515 UTC [52051] LOG: received smart shutdown request19232026-10-01 10:31:48.515 UTC [52051] LOG: background worker "logical replication launcher" (PID 52061) exited with exit code 119242026-10-01 10:31:48.519 UTC [52056] LOG: shutting down19252026-10-01 10:31:48.519 UTC [52056] LOG: checkpoint starting: shutdown immediate19262026-10-01 10:31:49.739 UTC [52056] LOG: checkpoint complete: wrote 12718 buffers (77.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.689 s, sync=0.497 s, total=1.220 s; sync files=29319, longest=0.001 s, average=0.001 s; distance=412524 kB, estimate=412524 kB; lsn=0/1AA68160, redo lsn=0/1AA6816019272026-10-01 10:31:49.744 UTC [52051] LOG: database system is shut down1928Running OIDC tests...1929=== RUN TestAudienceForIssuer1930=== PAUSE TestAudienceForIssuer1931=== RUN TestGlobMatch1932=== PAUSE TestGlobMatch1933=== RUN TestValidateToken_ValidToken1934=== PAUSE TestValidateToken_ValidToken1935=== RUN TestValidateToken_WrongAudience1936=== PAUSE TestValidateToken_WrongAudience1937=== RUN TestValidateToken_Expired1938=== PAUSE TestValidateToken_Expired1939=== RUN TestValidateToken_BoundClaimsMismatch1940=== PAUSE TestValidateToken_BoundClaimsMismatch1941=== RUN TestValidateToken_BoundSubjectMismatch1942=== PAUSE TestValidateToken_BoundSubjectMismatch1943=== RUN TestValidateToken_MultipleProviders1944=== PAUSE TestValidateToken_MultipleProviders1945=== RUN TestValidateToken_NoMatchingProvider1946=== PAUSE TestValidateToken_NoMatchingProvider1947=== RUN TestValidateToken_KubernetesServiceAccount1948=== PAUSE TestValidateToken_KubernetesServiceAccount1949=== RUN TestNewValidator_KubernetesRequiresCA1950=== PAUSE TestNewValidator_KubernetesRequiresCA1951=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1952=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1953=== RUN TestPins_ReservedForMatchingRule1954=== PAUSE TestPins_ReservedForMatchingRule1955=== RUN TestPins_TopLevelShorthand1956=== PAUSE TestPins_TopLevelShorthand1957=== RUN TestPins_ConfigValidation1958=== PAUSE TestPins_ConfigValidation1959=== RUN TestScopes_LegacyProviderDefaultsToWrite1960=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1961=== RUN TestScopes_Rules1962=== PAUSE TestScopes_Rules1963=== RUN TestScopes_ConfigValidation1964=== PAUSE TestScopes_ConfigValidation1965=== CONT TestAudienceForIssuer1966=== CONT TestValidateToken_KubernetesServiceAccount1967--- PASS: TestAudienceForIssuer (0.00s)1968=== CONT TestValidateToken_NoMatchingProvider1969=== CONT TestPins_ConfigValidation1970=== CONT TestScopes_Rules1971=== CONT TestScopes_LegacyProviderDefaultsToWrite1972=== CONT TestPins_ReservedForMatchingRule1973=== CONT TestValidateToken_Expired1974=== CONT TestValidateToken_BoundSubjectMismatch1975=== CONT TestPins_TopLevelShorthand1976=== CONT TestScopes_ConfigValidation1977--- PASS: TestScopes_ConfigValidation (0.00s)1978=== CONT TestValidateToken_MultipleProviders1979--- PASS: TestPins_ConfigValidation (0.01s)1980=== CONT TestValidateToken_KubernetesIssuerFromOwnToken19812026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63286/oidc1982--- PASS: TestValidateToken_Expired (0.04s)1983=== CONT TestNewValidator_KubernetesRequiresCA19842026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63288/oidc19852026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63290/oidc19862026/10/01 10:31:51 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1231987--- PASS: TestPins_TopLevelShorthand (0.06s)1988=== CONT TestValidateToken_WrongAudience1989--- PASS: TestPins_ReservedForMatchingRule (0.06s)1990=== CONT TestValidateToken_ValidToken1991--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)1992=== CONT TestGlobMatch1993=== RUN TestGlobMatch/foo_foo1994=== PAUSE TestGlobMatch/foo_foo1995=== RUN TestGlobMatch/foo_bar1996=== PAUSE TestGlobMatch/foo_bar1997=== RUN TestGlobMatch/*_1998=== PAUSE TestGlobMatch/*_1999=== RUN TestGlobMatch/*_anything2000=== PAUSE TestGlobMatch/*_anything2001=== RUN TestGlobMatch/foo*_foo2002=== PAUSE TestGlobMatch/foo*_foo2003=== RUN TestGlobMatch/foo*_foobar2004=== PAUSE TestGlobMatch/foo*_foobar2005=== RUN TestGlobMatch/foo*_bar2006=== PAUSE TestGlobMatch/foo*_bar2007=== RUN TestGlobMatch/*bar_bar2008=== PAUSE TestGlobMatch/*bar_bar2009=== RUN TestGlobMatch/*bar_foobar2010=== PAUSE TestGlobMatch/*bar_foobar2011=== RUN TestGlobMatch/*bar_foo2012=== PAUSE TestGlobMatch/*bar_foo2013=== RUN TestGlobMatch/foo*bar_foobar2014=== PAUSE TestGlobMatch/foo*bar_foobar2015=== RUN TestGlobMatch/foo*bar_foo123bar2016=== PAUSE TestGlobMatch/foo*bar_foo123bar2017=== RUN TestGlobMatch/foo*bar_foobarbaz2018=== PAUSE TestGlobMatch/foo*bar_foobarbaz2019=== RUN TestGlobMatch/*/*_foo/bar2020=== PAUSE TestGlobMatch/*/*_foo/bar2021=== RUN TestGlobMatch/*/*_foo2022=== PAUSE TestGlobMatch/*/*_foo2023=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2024=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2025=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02026=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02027=== RUN TestGlobMatch/refs/*/main_refs/heads/main2028=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2029=== RUN TestGlobMatch/fo?_foo2030=== PAUSE TestGlobMatch/fo?_foo2031=== RUN TestGlobMatch/fo?_fo2032=== PAUSE TestGlobMatch/fo?_fo2033=== RUN TestGlobMatch/fo?_fooo2034=== PAUSE TestGlobMatch/fo?_fooo2035=== RUN TestGlobMatch/?oo_foo2036=== PAUSE TestGlobMatch/?oo_foo2037=== RUN TestGlobMatch/?oo_boo2038=== PAUSE TestGlobMatch/?oo_boo2039=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2040=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2041=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2042=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2043=== CONT TestValidateToken_BoundClaimsMismatch20442026/10/01 10:31:51 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63285/oidc2045--- PASS: TestValidateToken_NoMatchingProvider (0.07s)2046=== CONT TestGlobMatch/foo_foo2047=== CONT TestGlobMatch/*/*_foo/bar2048=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2049=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2050=== CONT TestGlobMatch/?oo_boo2051=== CONT TestGlobMatch/?oo_foo2052=== CONT TestGlobMatch/fo?_fooo2053=== CONT TestGlobMatch/fo?_fo2054=== CONT TestGlobMatch/fo?_foo2055=== CONT TestGlobMatch/refs/*/main_refs/heads/main2056=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02057=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2058=== CONT TestGlobMatch/*/*_foo2059=== CONT TestGlobMatch/*bar_bar2060=== CONT TestGlobMatch/foo*bar_foobarbaz2061=== CONT TestGlobMatch/foo*bar_foo123bar2062=== CONT TestGlobMatch/foo*bar_foobar2063=== CONT TestGlobMatch/*bar_foo2064=== CONT TestGlobMatch/*bar_foobar2065=== CONT TestGlobMatch/foo*_foo2066=== CONT TestGlobMatch/foo*_bar2067=== CONT TestGlobMatch/foo*_foobar2068=== CONT TestGlobMatch/*_2069=== CONT TestGlobMatch/*_anything2070=== CONT TestGlobMatch/foo_bar2071--- PASS: TestGlobMatch (0.00s)2072 --- PASS: TestGlobMatch/foo_foo (0.00s)2073 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2074 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2075 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2076 --- PASS: TestGlobMatch/?oo_boo (0.00s)2077 --- PASS: TestGlobMatch/?oo_foo (0.00s)2078 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2079 --- PASS: TestGlobMatch/fo?_fo (0.00s)2080 --- PASS: TestGlobMatch/fo?_foo (0.00s)2081 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2082 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2083 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2084 --- PASS: TestGlobMatch/*/*_foo (0.00s)2085 --- PASS: TestGlobMatch/*bar_bar (0.00s)2086 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2087 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2088 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2089 --- PASS: TestGlobMatch/*bar_foo (0.00s)2090 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2091 --- PASS: TestGlobMatch/foo*_foo (0.00s)2092 --- PASS: TestGlobMatch/foo*_bar (0.00s)2093 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2094 --- PASS: TestGlobMatch/*_ (0.00s)2095 --- PASS: TestGlobMatch/*_anything (0.00s)2096 --- PASS: TestGlobMatch/foo_bar (0.00s)20972026/10/01 10:31:51 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:632962098--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)20992026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63298/oidc2100--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)21012026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63301/oidc2102--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)21032026/10/01 10:31:51 http: TLS handshake error from 127.0.0.1:63304: remote error: tls: bad certificate2104--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)21052026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63305/oidc2106--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)21072026/10/01 10:31:51 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63300/oidc21082026/10/01 10:31:51 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:63307/oidc2109--- PASS: TestValidateToken_MultipleProviders (0.14s)21102026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63310/oidc2111--- PASS: TestScopes_Rules (0.15s)21122026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63312/oidc2113--- PASS: TestValidateToken_ValidToken (0.11s)21142026/10/01 10:31:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63314/oidc2115--- PASS: TestValidateToken_WrongAudience (0.13s)2116PASS2117Running hook tests...2118=== RUN TestSendPathsEmpty2119=== PAUSE TestSendPathsEmpty2120=== RUN TestQueueEnqueueAndFetch2121=== PAUSE TestQueueEnqueueAndFetch2122=== RUN TestQueueDeduplication2123=== PAUSE TestQueueDeduplication2124=== RUN TestQueueRemove2125=== PAUSE TestQueueRemove2126=== RUN TestQueueFetchBatchLimit2127=== PAUSE TestQueueFetchBatchLimit2128=== RUN TestQueueRetryMovesToBack2129=== PAUSE TestQueueRetryMovesToBack2130=== RUN TestQueueFetchRemoveLifecycle2131=== PAUSE TestQueueFetchRemoveLifecycle2132=== RUN TestQueueConcurrentWriters2133=== PAUSE TestQueueConcurrentWriters2134=== RUN TestQueueRemoveLargeClosure2135=== PAUSE TestQueueRemoveLargeClosure2136=== RUN TestServerClientIntegration2137=== PAUSE TestServerClientIntegration2138=== RUN TestServerQueueError2139=== PAUSE TestServerQueueError2140=== RUN TestGetListenerSocketActivation2141 server_test.go:210: === RUN TestGetListenerSocketActivation2142 --- PASS: TestGetListenerSocketActivation (0.00s)2143 PASS2144 2145--- PASS: TestGetListenerSocketActivation (0.01s)2146=== RUN TestDrainIsolatesPoisonPath2147=== PAUSE TestDrainIsolatesPoisonPath2148=== RUN TestRunNotBlockedByPoisonHead2149=== PAUSE TestRunNotBlockedByPoisonHead2150=== RUN TestDrainGivesUpWhenServerDown2151=== PAUSE TestDrainGivesUpWhenServerDown2152=== RUN TestFailedPathPrunedByLaterClosure2153=== PAUSE TestFailedPathPrunedByLaterClosure2154=== RUN TestWorkerUploadsAndRemoves2155=== PAUSE TestWorkerUploadsAndRemoves2156=== RUN TestWorkerSkipsGCdPaths2157=== PAUSE TestWorkerSkipsGCdPaths2158=== RUN TestWorkerPrunesClosureDeps2159=== PAUSE TestWorkerPrunesClosureDeps2160=== RUN TestDrainTimeout2161=== PAUSE TestDrainTimeout2162=== CONT TestSendPathsEmpty2163=== CONT TestServerQueueError2164--- PASS: TestSendPathsEmpty (0.00s)2165=== CONT TestQueueRetryMovesToBack2166=== CONT TestQueueFetchBatchLimit2167=== CONT TestQueueRemove2168=== CONT TestQueueDeduplication2169=== CONT TestQueueEnqueueAndFetch2170=== CONT TestWorkerUploadsAndRemoves2171=== CONT TestDrainTimeout2172=== CONT TestWorkerPrunesClosureDeps2173=== CONT TestWorkerSkipsGCdPaths21742026/10/01 10:31:51 ERROR Failed to queue paths error="permission denied" count=12175--- PASS: TestServerQueueError (0.00s)2176=== CONT TestQueueRemoveLargeClosure21772026/10/01 10:31:51 INFO Upload queue status pending=221782026/10/01 10:31:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-51998-174198025/TestWorkerSkipsGCdPaths3693757151/002/nonexistent21792026/10/01 10:31:51 INFO Uploading batch count=12180--- PASS: TestQueueEnqueueAndFetch (0.01s)2181=== CONT TestServerClientIntegration21822026/10/01 10:31:51 INFO Uploading batch count=221832026/10/01 10:31:51 INFO Upload queue status pending=221842026/10/01 10:31:51 INFO Uploading batch count=12185--- PASS: TestQueueRetryMovesToBack (0.01s)2186=== CONT TestDrainGivesUpWhenServerDown21872026/10/01 10:31:51 INFO Upload queue status pending=22188--- PASS: TestQueueRemove (0.01s)2189=== CONT TestFailedPathPrunedByLaterClosure2190--- PASS: TestQueueFetchBatchLimit (0.01s)2191=== CONT TestQueueConcurrentWriters21922026/10/01 10:31:51 INFO Uploading batch count=22193--- PASS: TestQueueDeduplication (0.01s)2194=== CONT TestRunNotBlockedByPoisonHead2195--- PASS: TestServerClientIntegration (0.00s)2196=== CONT TestDrainIsolatesPoisonPath21972026/10/01 10:31:51 INFO Uploading batch count=121982026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=121992026/10/01 10:31:51 INFO Upload queue status pending=322002026/10/01 10:31:51 INFO Uploading batch count=122012026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=122022026/10/01 10:31:51 INFO Uploading batch count=122032026/10/01 10:31:51 INFO Uploading batch count=222042026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=222052026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/a22062026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/b22072026/10/01 10:31:51 INFO Uploading batch count=122082026/10/01 10:31:51 INFO Uploading batch count=422092026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=422102026/10/01 10:31:51 INFO Uploading batch count=222112026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=222122026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/c22132026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainIsolatesPoisonPath897953808/002/bbb22142026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/d22152026/10/01 10:31:51 INFO Uploading batch count=222162026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=222172026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/e22182026/10/01 10:31:51 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51998-174198025/TestDrainGivesUpWhenServerDown3668830050/002/f22192026/10/01 10:31:51 INFO Uploading batch count=122202026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=122212026/10/01 10:31:51 INFO Uploading batch count=122222026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=122232026/10/01 10:31:51 ERROR Drain finished with paths left in queue remaining=1022242026/10/01 10:31:51 INFO Uploading batch count=122252026/10/01 10:31:51 ERROR Upload failed error="upload failed" count=122262026/10/01 10:31:51 ERROR Drain finished with paths left in queue remaining=12227--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2228=== CONT TestQueueFetchRemoveLifecycle2229--- PASS: TestDrainIsolatesPoisonPath (0.01s)2230--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2231--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2232--- PASS: TestWorkerSkipsGCdPaths (0.03s)2233--- PASS: TestWorkerPrunesClosureDeps (0.03s)2234--- PASS: TestWorkerUploadsAndRemoves (0.03s)2235--- PASS: TestQueueRemoveLargeClosure (0.05s)2236--- PASS: TestQueueConcurrentWriters (0.15s)22372026/10/01 10:31:51 ERROR Upload failed error="context deadline exceeded" count=222382026/10/01 10:31:51 ERROR Drain finished with paths left in queue remaining=42239--- PASS: TestDrainTimeout (0.21s)22402026/10/01 10:31:52 INFO Uploading batch count=122412026/10/01 10:31:52 INFO Uploading batch count=122422026/10/01 10:31:52 INFO Uploading batch count=122432026/10/01 10:31:52 ERROR Upload failed error="upload failed" count=122442026/10/01 10:31:52 INFO Uploading batch count=122452026/10/01 10:31:52 ERROR Upload failed error="upload failed" count=122462026/10/01 10:31:52 INFO Uploading batch count=122472026/10/01 10:31:52 ERROR Upload failed error="upload failed" count=122482026/10/01 10:31:52 INFO Uploading batch count=122492026/10/01 10:31:52 ERROR Upload failed error="upload failed" count=122502026/10/01 10:31:52 ERROR Drain finished with paths left in queue remaining=12251--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2252PASS