niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #352
· 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.06s)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 TestSetClientTLSErrors97=== CONT TestEncodeNixBase32WithRealHash98--- PASS: TestEncodeNixBase32WithRealHash (0.00s)99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100--- PASS: TestShellSplit (0.00s)101=== CONT TestResolveStorePath102=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess103=== CONT TestPathInfoHashCompatibility104=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)105=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)106=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon107=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon108=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI109=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI110=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512111=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512112=== CONT TestGetStorePathHash113=== RUN TestGetStorePathHash/valid_store_path114=== PAUSE TestGetStorePathHash/valid_store_path115=== RUN TestGetStorePathHash/basename_without_hyphen_should_error116=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error117=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error118=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error119=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error120=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error121=== CONT TestConvertHashToNix32122=== RUN TestConvertHashToNix32/SRI_format_to_Nix32123=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32124=== RUN TestConvertHashToNix32/already_Nix32_format125=== PAUSE TestConvertHashToNix32/already_Nix32_format126=== RUN TestConvertHashToNix32/invalid_format127=== PAUSE TestConvertHashToNix32/invalid_format128=== CONT TestStreamPushRequestLine1292026/10/04 19:45:58 WARN Rate limiter enabled after throttle name=server-test rate=5130--- PASS: TestResolveStorePath (0.00s)131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport132=== CONT TestRateLimiterFeedback133=== RUN TestRateLimiterFeedback/429_enables_limiter134=== PAUSE TestRateLimiterFeedback/429_enables_limiter135=== RUN TestRateLimiterFeedback/503_enables_limiter136=== PAUSE TestRateLimiterFeedback/503_enables_limiter137=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter138=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter139=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter140=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter141=== CONT TestSetClientTLS142=== CONT TestPathInfoCACompatibility143=== RUN TestPathInfoCACompatibility/null_ca_field144=== PAUSE TestPathInfoCACompatibility/null_ca_field145=== RUN TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text147=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive149=== RUN TestPathInfoCACompatibility/new_structured_format_-_text150=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text151=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method152=== CONT TestParsePathInfoJSONMultiplePaths153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method154=== CONT TestParsePathInfoJSON155=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1562026/10/04 19:45:58 WARN Rate limiter enabled after throttle name=server-test rate=51572026/10/04 19:45:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65162158=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths160=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== CONT TestClientSignaturesByStorePath162--- PASS: TestClientSignaturesByStorePath (0.00s)163=== CONT TestStreamPushBatchesUnderLoad164=== CONT TestStreamPushReportsSignatures1652026/10/04 19:45:58 ERROR Upload failed error=boom count=1166=== RUN TestParsePathInfoJSON/Nix_format167=== PAUSE TestParsePathInfoJSON/Nix_format168=== RUN TestParsePathInfoJSON/Lix_format1692026/10/04 19:45:58 ERROR Upload failed error=boom count=1170=== PAUSE TestParsePathInfoJSON/Lix_format171=== RUN TestParsePathInfoJSON/empty_input172--- PASS: TestStreamPushReportsSignatures (0.00s)173=== CONT TestStreamPushGivesUpOnDeadServer174=== PAUSE TestParsePathInfoJSON/empty_input175=== RUN TestParsePathInfoJSON/whitespace_only1762026/10/04 19:45:58 ERROR Upload failed error="connection refused" count=111772026/10/04 19:45:58 ERROR Server seems unavailable, giving up on batch untried=81782026/10/04 19:45:58 WARN Rate limiter backed off name=server-test rate=51792026/10/04 19:45:58 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65162180=== PAUSE TestParsePathInfoJSON/whitespace_only181=== RUN TestParsePathInfoJSON/invalid_JSON1822026/10/04 19:45:58 ERROR Upload failed error="connection refused" count=91832026/10/04 19:45:58 ERROR Server seems unavailable, giving up on batch untried=6184--- PASS: TestDoServerRequestAttachesToken (0.00s)185=== PAUSE TestParsePathInfoJSON/invalid_JSON186=== CONT TestStreamPushIsolatesFailures187=== CONT TestUploadMultipart_SupersededByPeer188=== RUN TestUploadMultipart_SupersededByPeer/exists189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)191=== RUN TestSetClientTLSErrors/missing_cert_file1922026/10/04 19:45:58 ERROR Upload failed error="bad path" count=3193=== RUN TestUploadMultipart_SupersededByPeer/missing194=== PAUSE TestUploadMultipart_SupersededByPeer/missing195=== CONT TestEncodeNixBase32196=== RUN TestEncodeNixBase32/test_string_hash197=== PAUSE TestEncodeNixBase32/test_string_hash198=== CONT TestDumpPathSingleFile199=== RUN TestEncodeNixBase32/empty_input200=== PAUSE TestEncodeNixBase32/empty_input201--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)202--- PASS: TestStreamPushIsolatesFailures (0.00s)203=== CONT TestDumpPathWriterError204=== PAUSE TestSetClientTLSErrors/missing_cert_file205=== RUN TestSetClientTLSErrors/missing_key_file206=== PAUSE TestSetClientTLSErrors/missing_key_file207=== RUN TestSetClientTLSErrors/missing_ca_file208=== PAUSE TestSetClientTLSErrors/missing_ca_file209=== RUN TestSetClientTLSErrors/invalid_ca_file210=== PAUSE TestSetClientTLSErrors/invalid_ca_file211=== CONT TestDumpPathMatchesNix212=== CONT TestShellSplitErrors213--- PASS: TestShellSplitErrors (0.00s)214=== CONT TestScriptTokenCachesUntilRefresh215=== CONT TestStreamPushReportsEveryPath216--- PASS: TestStreamPushReportsEveryPath (0.00s)217=== CONT TestScriptTokenEmptyCommand218--- PASS: TestScriptTokenEmptyCommand (0.00s)219=== CONT TestScriptTokenScriptFails220--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)221=== CONT TestScriptTokenBadJSON222=== RUN TestSetClientTLS/rejects_connection_without_client_cert223=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert224=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA225=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA226=== RUN TestSetClientTLS/preserves_debug_logging_transport227=== PAUSE TestSetClientTLS/preserves_debug_logging_transport228=== CONT TestScriptTokenEmptyToken229--- PASS: TestScriptTokenScriptFails (0.00s)230=== CONT TestFilterOversizedClosures231=== RUN TestFilterOversizedClosures/no_limit_keeps_everything232=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything233=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== RUN TestFilterOversizedClosures/all_closures_skipped236=== PAUSE TestFilterOversizedClosures/all_closures_skipped237=== CONT TestPartSizeForNAR238=== RUN TestPartSizeForNAR/zero_stays_at_minimum239=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum240=== RUN TestPartSizeForNAR/small_stays_at_minimum241=== PAUSE TestPartSizeForNAR/small_stays_at_minimum242=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum243=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum244=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts245=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts246=== RUN TestPartSizeForNAR/1_TiB247=== PAUSE TestPartSizeForNAR/1_TiB248=== RUN TestPartSizeForNAR/5_TiB_S3_max_object249=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object250=== RUN TestPartSizeForNAR/capped_at_5_GiB251=== PAUSE TestPartSizeForNAR/capped_at_5_GiB252=== CONT TestUploadMultipart_PartsInParallel253--- PASS: TestScriptTokenBadJSON (0.01s)254=== CONT TestCaseHackSuffix255--- PASS: TestScriptTokenEmptyToken (0.01s)256=== CONT TestFileTokenMissing257--- PASS: TestFileTokenMissing (0.00s)258=== CONT TestScriptTokenNoExpiryRerunsEveryCall259--- PASS: TestStreamPushRequestLine (0.02s)260=== CONT TestFileTokenEmpty261--- PASS: TestFileTokenEmpty (0.00s)262=== CONT TestFileTokenReadsAndCaches263--- PASS: TestFileTokenReadsAndCaches (0.00s)264=== CONT TestStaticToken265--- PASS: TestStaticToken (0.00s)266=== CONT TestRegisterUploadedObjectReusesConnections267--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)268=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)269=== CONT TestGetStorePathHash/valid_store_path270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon273--- PASS: TestPathInfoHashCompatibility (0.00s)274 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)275 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)276 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)277 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)278=== CONT TestConvertHashToNix32/SRI_format_to_Nix32279=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error280=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error281=== CONT TestGetStorePathHash/basename_without_hyphen_should_error282=== CONT TestConvertHashToNix32/already_Nix32_format283=== CONT TestConvertHashToNix32/invalid_format284=== CONT TestRateLimiterFeedback/429_enables_limiter285--- PASS: TestGetStorePathHash (0.00s)286 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)287 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)288 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)289 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)290--- PASS: TestConvertHashToNix32 (0.00s)291 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)292 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)293 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)2942026/10/04 19:45:58 WARN Rate limiter enabled after throttle name=server-test rate=52952026/10/04 19:45:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:652382962026/10/04 19:45:58 WARN Rate limiter backed off name=server-test rate=5297=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter298=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter299=== CONT TestRateLimiterFeedback/503_enables_limiter3002026/10/04 19:45:58 WARN Rate limiter enabled after throttle name=server-test rate=53012026/10/04 19:45:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:652443022026/10/04 19:45:58 WARN Rate limiter backed off name=server-test rate=5303--- PASS: TestRateLimiterFeedback (0.00s)304 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)305 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)306 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)307 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)308=== CONT TestPathInfoCACompatibility/null_ca_field309=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive310=== CONT TestPathInfoCACompatibility/old_string_format_-_text311=== CONT TestPathInfoCACompatibility/new_structured_format_-_text312=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method313--- PASS: TestPathInfoCACompatibility (0.00s)314 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)317 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)319=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths320=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths321--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)322 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)323 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)324=== CONT TestParsePathInfoJSON/Nix_format325=== CONT TestParsePathInfoJSON/whitespace_only326=== CONT TestParsePathInfoJSON/empty_input327=== CONT TestParsePathInfoJSON/Lix_format328=== CONT TestParsePathInfoJSON/invalid_JSON329--- PASS: TestParsePathInfoJSON (0.00s)330 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)331 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)332 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)333 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)335=== CONT TestUploadMultipart_SupersededByPeer/exists336=== CONT TestUploadMultipart_SupersededByPeer/missing337--- PASS: TestDumpPathWriterError (0.04s)338=== CONT TestEncodeNixBase32/test_string_hash339=== CONT TestEncodeNixBase32/empty_input340--- PASS: TestEncodeNixBase32 (0.00s)341 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)342 --- PASS: TestEncodeNixBase32/empty_input (0.00s)343=== CONT TestSetClientTLSErrors/missing_cert_file344=== CONT TestSetClientTLSErrors/invalid_ca_file345=== CONT TestSetClientTLSErrors/missing_ca_file346=== CONT TestSetClientTLSErrors/missing_key_file347=== CONT TestSetClientTLS/rejects_connection_without_client_cert348--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)349 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)350 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)351--- PASS: TestSetClientTLSErrors (0.00s)352 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)353 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)355 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)356=== CONT TestSetClientTLS/preserves_debug_logging_transport357=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA358--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)359=== CONT TestFilterOversizedClosures/no_limit_keeps_everything360=== CONT TestFilterOversizedClosures/all_closures_skipped3612026/10/04 19:45:58 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=50362=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3632026/10/04 19:45:58 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=2000364--- PASS: TestFilterOversizedClosures (0.00s)365 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)366 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)367 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)368=== CONT TestPartSizeForNAR/zero_stays_at_minimum369=== CONT TestPartSizeForNAR/1_TiB370=== CONT TestPartSizeForNAR/capped_at_5_GiB371=== CONT TestPartSizeForNAR/5_TiB_S3_max_object372=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum373=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts374=== CONT TestPartSizeForNAR/small_stays_at_minimum375--- PASS: TestPartSizeForNAR (0.00s)376 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)377 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)378 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)379 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)382 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)383--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)3842026/10/04 19:45:58 http: TLS handshake error from 127.0.0.1:65250: remote error: tls: bad certificate385--- PASS: TestSetClientTLS (0.00s)386 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)387 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)388 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)389--- PASS: TestDumpPathSingleFile (0.06s)390--- PASS: TestCaseHackSuffix (0.04s)391--- PASS: TestDumpPathMatchesNix (0.07s)392--- PASS: TestStreamPushBatchesUnderLoad (0.10s)393--- PASS: TestUploadMultipart_PartsInParallel (0.61s)394--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)395PASS396Running server tests...397The files belonging to this database system will be owned by user "_nixbld1".398This user must also own the server process.399400The database cluster will be initialized with locale "C".401The default database encoding has accordingly been set to "SQL_ASCII".402The default text search configuration will be set to "english".403404Data page checksums are enabled.405406creating directory /nix/var/nix/builds/nix-96338-3122596536/postgres3470020243/data ... ok407creating subdirectories ... ok408selecting dynamic shared memory implementation ... posix409selecting default "max_connections" ... 100410selecting default "shared_buffers" ... 128MB411selecting default time zone ... UTC412creating configuration files ... ok413running bootstrap script ... ok414performing post-bootstrap initialization ... ok415syncing data to disk ... ok416417initdb: warning: enabling "trust" authentication for local connections418initdb: 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.419420Success. You can now start the database server using:421422 pg_ctl -D /nix/var/nix/builds/nix-96338-3122596536/postgres3470020243/data -l logfile start423424/nix/var/nix/builds/nix-96338-3122596536/postgres3470020243:5432 - no response4252026-10-04 19:46:00.371 UTC [96378] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4262026-10-04 19:46:00.372 UTC [96378] LOG: listening on Unix socket "/nix/var/nix/builds/nix-96338-3122596536/postgres3470020243/.s.PGSQL.5432"4272026-10-04 19:46:00.374 UTC [96385] LOG: database system was shut down at 2026-10-04 19:46:00 UTC4282026-10-04 19:46:00.374 UTC [96378] LOG: database system is ready to accept connections429/nix/var/nix/builds/nix-96338-3122596536/postgres3470020243:5432 - accepting connections430{"timestamp":"2026-10-04T19:46:00.591526Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8fd9242a-955f-4531-928c-57b1c9ac4f04","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}431=== RUN TestService_AuthMiddleware432=== PAUSE TestService_AuthMiddleware433=== RUN TestService_AuthMiddleware_MTLSProxyHeader434=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader435=== RUN TestService_AuthMiddleware_MTLSBoundSubjects436=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects437=== RUN TestService_ReadAuthMiddleware438=== PAUSE TestService_ReadAuthMiddleware439=== RUN TestService_AuthMiddleware_OIDC440=== PAUSE TestService_AuthMiddleware_OIDC441=== RUN TestService_RequireScope_OIDC442=== PAUSE TestService_RequireScope_OIDC443=== RUN TestService_ReadScope_PublicByDefault444=== PAUSE TestService_ReadScope_PublicByDefault445=== RUN TestCacheConfigHandler446=== PAUSE TestCacheConfigHandler447=== RUN TestCacheStatsHandler448=== PAUSE TestCacheStatsHandler449=== RUN TestClientCADerivations450=== PAUSE TestClientCADerivations451=== RUN TestClientErrorHandling452=== PAUSE TestClientErrorHandling453=== RUN TestClientIntegration454=== PAUSE TestClientIntegration455=== RUN TestClientMultipleUploads456=== PAUSE TestClientMultipleUploads457=== RUN TestClientWithDependencies458=== PAUSE TestClientWithDependencies459=== RUN TestClientSharedPathCommittedMidPush460=== PAUSE TestClientSharedPathCommittedMidPush461=== RUN TestPinProtectsFromGC462=== PAUSE TestPinProtectsFromGC463=== RUN TestClientPushesUseOnePush464=== PAUSE TestClientPushesUseOnePush465=== RUN TestClientFallsBackToClosures466=== PAUSE TestClientFallsBackToClosures467=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock469=== RUN TestResolveDBConnectionString470=== PAUSE TestResolveDBConnectionString471=== RUN TestConnectWaitsForAPeerMigration472=== PAUSE TestConnectWaitsForAPeerMigration473=== RUN TestLeadElectsOneAndHandsOver474=== PAUSE TestLeadElectsOneAndHandsOver475=== RUN TestLeadIncumbentWinsAfterRestart4762026/10/04 19:46:00 INFO lead: acquired remote=192.0.2.1:12344772026/10/04 19:46:01 INFO lead: released remote=192.0.2.1:12344782026/10/04 19:46:02 INFO lead: acquired remote=192.0.2.1:12344792026/10/04 19:46:03 INFO lead: released remote=192.0.2.1:1234480--- PASS: TestLeadIncumbentWinsAfterRestart (2.44s)481=== RUN TestLeadEndsOnShutdown482=== PAUSE TestLeadEndsOnShutdown483=== RUN TestLeadEndsWhenItsConnectionHangs4842026/10/04 19:46:03 INFO lead: acquired remote=192.0.2.1:12344852026-10-04 19:46:04.489 UTC [96420] FATAL: terminating connection due to administrator command4862026/10/04 19:46:04 INFO lead: acquired remote=192.0.2.1:12344872026/10/04 19:46:05 WARN lead: lock connection lost error="timeout: context deadline exceeded"4882026/10/04 19:46:05 INFO lead: released remote=192.0.2.1:12344892026/10/04 19:46:05 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadEndsWhenItsConnectionHangs (2.75s)491=== RUN TestGCAdvisoryLockBlocksConcurrentRun492=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun493=== RUN TestGCBugBareHashReferences494=== PAUSE TestGCBugBareHashReferences495=== RUN TestGCMetrics496=== PAUSE TestGCMetrics497=== RUN TestPushDedupSurvivesConcurrentGC498=== PAUSE TestPushDedupSurvivesConcurrentGC499=== RUN TestDeduplicatedObjectsRecordedAsPending500=== PAUSE TestDeduplicatedObjectsRecordedAsPending501=== RUN TestGCSweepSkipsPendingObjects502=== PAUSE TestGCSweepSkipsPendingObjects503=== RUN TestTombstonedObjectOfferedWithoutWaiting504=== PAUSE TestTombstonedObjectOfferedWithoutWaiting505=== RUN TestGCSweepDeliversEachKeyOnce506=== PAUSE TestGCSweepDeliversEachKeyOnce507=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection508=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection509=== RUN TestForceGCDuringPushOffersSweptObject510=== PAUSE TestForceGCDuringPushOffersSweptObject511=== RUN TestFailedS3DeleteKeepsTombstone512=== PAUSE TestFailedS3DeleteKeepsTombstone513=== RUN TestSweepSkipsRowsLockedByPush514=== PAUSE TestSweepSkipsRowsLockedByPush515=== RUN TestRegisterCompletedObjectNeedsPendingRow516=== PAUSE TestRegisterCompletedObjectNeedsPendingRow517=== RUN TestGetExistingObjectsLocksRows518=== PAUSE TestGetExistingObjectsLocksRows519=== RUN TestSweepRechecksPendingAfterLocking520=== PAUSE TestSweepRechecksPendingAfterLocking521=== RUN TestPushWaitsForSweepHoldingRow522=== PAUSE TestPushWaitsForSweepHoldingRow523=== RUN TestCommitRacingPendingCleanupKeepsObjects524=== PAUSE TestCommitRacingPendingCleanupKeepsObjects525=== RUN TestGCEndsOnShutdown526=== PAUSE TestGCEndsOnShutdown527=== RUN TestGCTaskStore_StartNew528=== PAUSE TestGCTaskStore_StartNew529=== RUN TestGCTaskStore_DeduplicateSameParams530=== PAUSE TestGCTaskStore_DeduplicateSameParams531=== RUN TestGCTaskStore_ConflictDifferentParams532=== PAUSE TestGCTaskStore_ConflictDifferentParams533=== RUN TestGCTaskStore_GetEmpty534=== PAUSE TestGCTaskStore_GetEmpty535=== RUN TestGCTaskStore_GetReturnsLatest536=== PAUSE TestGCTaskStore_GetReturnsLatest537=== RUN TestGCTaskStore_CompletedAllowsNewTask538=== PAUSE TestGCTaskStore_CompletedAllowsNewTask539=== RUN TestGCTaskStore_PhaseUpdates540=== PAUSE TestGCTaskStore_PhaseUpdates541=== RUN TestGCTaskStore_Fail542=== PAUSE TestGCTaskStore_Fail543=== RUN TestGracefulShutdownDrainsInflight544=== PAUSE TestGracefulShutdownDrainsInflight545=== RUN TestService_healthCheckHandler546=== PAUSE TestService_healthCheckHandler547=== RUN TestService_readinessHandler548=== PAUSE TestService_readinessHandler549=== RUN TestGenerateLandingPage550=== PAUSE TestGenerateLandingPage551=== RUN TestCacheConfigHandlerMaxNarSize552=== PAUSE TestCacheConfigHandlerMaxNarSize553=== RUN TestCreatePendingClosureRejectsOversizedNAR554=== PAUSE TestCreatePendingClosureRejectsOversizedNAR555=== RUN TestNARDeduplicationMetadataUploadBug556=== PAUSE TestNARDeduplicationMetadataUploadBug557=== RUN TestMetricsInventory558=== PAUSE TestMetricsInventory559=== RUN TestService_NativeMTLS560=== PAUSE TestService_NativeMTLS561=== RUN TestServerTLSConfig562=== PAUSE TestServerTLSConfig563=== RUN TestMultipartCleanup564=== PAUSE TestMultipartCleanup565=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded566=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded567=== RUN TestPendingCleanupUsesOneCutoff568=== PAUSE TestPendingCleanupUsesOneCutoff569=== RUN TestObjectStatsTrigger570=== PAUSE TestObjectStatsTrigger571=== RUN TestOrphanedObjectsGC572=== PAUSE TestOrphanedObjectsGC573=== RUN TestOrphanedObjectsGCStressTest574=== PAUSE TestOrphanedObjectsGCStressTest575=== RUN TestCreatePin_ReservedPins576=== PAUSE TestCreatePin_ReservedPins577=== RUN TestPresentReportsOnlyClosureRoots578=== PAUSE TestPresentReportsOnlyClosureRoots579=== RUN TestPresentNotReportedWhileGCDeletesClosure580=== PAUSE TestPresentNotReportedWhileGCDeletesClosure581=== RUN TestParseSingleRange582=== PAUSE TestParseSingleRange583=== RUN TestProxyHeadersOnlyTrustedOnSocket584=== PAUSE TestProxyHeadersOnlyTrustedOnSocket585=== RUN TestIsValidCachePath586=== PAUSE TestIsValidCachePath587=== RUN TestReadProxyNarinfo588=== PAUSE TestReadProxyNarinfo589=== RUN TestReadProxyNarinfoAlreadyDecompressed590=== PAUSE TestReadProxyNarinfoAlreadyDecompressed591=== RUN TestReadProxyNarStreaming592=== PAUSE TestReadProxyNarStreaming593=== RUN TestReadProxy404594=== PAUSE TestReadProxy404595=== RUN TestReadProxyInvalidPath596=== PAUSE TestReadProxyInvalidPath597=== RUN TestReadProxyHead598=== PAUSE TestReadProxyHead599=== RUN TestReadProxyOutlastsServerWriteTimeout600=== PAUSE TestReadProxyOutlastsServerWriteTimeout601=== RUN TestReadProxyConditionalGet602=== PAUSE TestReadProxyConditionalGet603=== RUN TestReadProxyRootRedirectsToIndexHTML604=== PAUSE TestReadProxyRootRedirectsToIndexHTML605=== RUN TestReadProxyDisabled606=== PAUSE TestReadProxyDisabled607=== RUN TestReadRedirectNar608=== PAUSE TestReadRedirectNar609=== RUN TestReadRedirectKeepsNarinfoProxied610=== PAUSE TestReadRedirectKeepsNarinfoProxied611=== RUN TestReadProxyRangeRequest612=== PAUSE TestReadProxyRangeRequest613=== RUN TestReadRedirectUsesPublicS3URL614=== PAUSE TestReadRedirectUsesPublicS3URL615=== RUN TestPush_OverlappingRootsStoreOneRowPerKey616=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey617=== RUN TestPush_CompleteCommitsEveryRoot618=== PAUSE TestPush_CompleteCommitsEveryRoot619=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit620=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit621=== RUN TestPush_RejectsBadRequests622=== PAUSE TestPush_RejectsBadRequests623=== RUN TestPush_SignsNarinfosOfItsPendingObjects624=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects625=== RUN TestRedundantMultipartUpload626=== PAUSE TestRedundantMultipartUpload627=== RUN TestCompleteMultipartUpload_ErrorButObjectExists628=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists629=== RUN TestCompletedNarNotReofferedAcrossClosures630=== PAUSE TestCompletedNarNotReofferedAcrossClosures631=== RUN TestPresignedUploadRegisteredBeforeCommit632=== PAUSE TestPresignedUploadRegisteredBeforeCommit633=== RUN TestService_Rustfstest634=== PAUSE TestService_Rustfstest635=== RUN TestParseSize636=== PAUSE TestParseSize637=== RUN TestSkippedUploadsHandler638=== PAUSE TestSkippedUploadsHandler639=== RUN TestSystemdListenerNotActivated640--- PASS: TestSystemdListenerNotActivated (0.00s)641=== RUN TestWatchdogBeatsWhenHealthy642--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)643=== RUN TestWatchdogSkipsWhenUnhealthy6442026/10/04 19:46:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/04 19:46:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/04 19:46:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/04 19:46:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"654--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)655=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle656=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle657=== RUN TestProxyWriteTimeout658=== PAUSE TestProxyWriteTimeout659=== RUN TestPendingClosureWriteTimeout660=== PAUSE TestPendingClosureWriteTimeout661=== RUN TestIsValidUploadKey662=== PAUSE TestIsValidUploadKey663=== RUN TestUploadHandlersRejectInvalidKeys664=== PAUSE TestUploadHandlersRejectInvalidKeys665=== RUN TestUploadHandlersRejectOversizedBody666=== PAUSE TestUploadHandlersRejectOversizedBody667=== RUN TestService_cleanupPendingClosuresHandler668=== PAUSE TestService_cleanupPendingClosuresHandler669=== RUN TestService_createPendingClosureHandler670=== PAUSE TestService_createPendingClosureHandler671=== RUN TestService_verifyS3Integrity672=== PAUSE TestService_verifyS3Integrity673=== RUN TestCompleteMultipartUnregistered674=== PAUSE TestCompleteMultipartUnregistered675=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT676=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT677=== CONT TestPush_CompleteCommitsEveryRoot678=== CONT TestServerTLSConfig679=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle680=== CONT TestPush_OverlappingRootsStoreOneRowPerKey681=== CONT TestService_AuthMiddleware682=== CONT TestTombstonedObjectOfferedWithoutWaiting683=== CONT TestUploadHandlersRejectOversizedBody684=== CONT TestCompleteMultipartUpload_ErrorButObjectExists685=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT686=== RUN TestServerTLSConfig/no_client_CA687=== PAUSE TestServerTLSConfig/no_client_CA688=== RUN TestServerTLSConfig/missing_CA_file689=== PAUSE TestServerTLSConfig/missing_CA_file690=== CONT TestCompletedNarNotReofferedAcrossClosures691=== RUN TestServerTLSConfig/not_a_PEM_file692=== PAUSE TestServerTLSConfig/not_a_PEM_file693=== CONT TestGCSweepSkipsPendingObjects694=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure695=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure696=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart697=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart698=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts699=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts700=== CONT TestDeduplicatedObjectsRecordedAsPending7012026/10/04 19:46:06 INFO Received push request method=POST path=/api/pushes7022026/10/04 19:46:06 INFO Received complete push request method=POST path=/api/pushes/1/complete703--- PASS: TestPush_CompleteCommitsEveryRoot (0.48s)704=== CONT TestPushDedupSurvivesConcurrentGC7052026/10/04 19:46:06 INFO Received push request method=POST path=/api/pushes706--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.63s)707=== CONT TestGCMetrics7082026/10/04 19:46:06 INFO Received uploads request method=POST path=/api/pending_closures709--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.81s)710=== CONT TestGCBugBareHashReferences7112026/10/04 19:46:07 INFO Received uploads request method=POST path=/api/pending_closures712--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.97s)713=== CONT TestGCAdvisoryLockBlocksConcurrentRun7142026/10/04 19:46:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"715--- PASS: TestService_AuthMiddleware (1.08s)716=== CONT TestLeadEndsOnShutdown7172026/10/04 19:46:07 INFO Received uploads request method=POST path=/api/pending_closures7182026/10/04 19:46:07 INFO Received uploads request method=POST path=/api/pending_closures7192026/10/04 19:46:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7202026/10/04 19:46:07 INFO Received uploads request method=POST path=/api/pending_closures721--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.66s)722=== CONT TestLeadElectsOneAndHandsOver7232026/10/04 19:46:08 INFO Received uploads request method=POST path=/api/pending_closures7242026/10/04 19:46:08 INFO Aborted multipart uploads count=0 kept=07252026/10/04 19:46:08 WARN Force mode enabled - objects will be deleted immediately without grace period7262026/10/04 19:46:08 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=07272026/10/04 19:46:08 INFO Vacuumed table table=pending_closures7282026/10/04 19:46:08 INFO Vacuumed table table=pending_objects7292026/10/04 19:46:08 INFO Vacuumed table table=multipart_uploads7302026/10/04 19:46:08 INFO Vacuumed table table=closures7312026/10/04 19:46:08 INFO Vacuumed table table=objects732--- PASS: TestGCSweepSkipsPendingObjects (2.03s)733=== CONT TestConnectWaitsForAPeerMigration7342026/10/04 19:46:08 INFO Received uploads request method=POST path=/api/pending_closures7352026/10/04 19:46:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7362026/10/04 19:46:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjcxYzRhOWE5LTJiMjQtNGMyOS04Zjc2LTkxMzQ4NWQ0OGU4MHgxNzkxMTQzMTY4MjU1MzEyMDAw7372026/10/04 19:46:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjcxYzRhOWE5LTJiMjQtNGMyOS04Zjc2LTkxMzQ4NWQ0OGU4MHgxNzkxMTQzMTY4MjU1MzEyMDAw parts=1738--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.36s)739=== CONT TestResolveDBConnectionString740=== RUN TestResolveDBConnectionString/flag_wins741=== PAUSE TestResolveDBConnectionString/flag_wins742=== RUN TestResolveDBConnectionString/file_when_flag_empty743=== PAUSE TestResolveDBConnectionString/file_when_flag_empty744=== RUN TestResolveDBConnectionString/missing_file_is_an_error745=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error746=== RUN TestResolveDBConnectionString/PGHOST_allows_empty747=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty748=== RUN TestResolveDBConnectionString/nothing_configured749=== PAUSE TestResolveDBConnectionString/nothing_configured750=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7512026/10/04 19:46:08 INFO Received uploads request method=POST path=/api/pending_closures7522026/10/04 19:46:08 INFO Aborted multipart uploads count=0 kept=07532026/10/04 19:46:08 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=07542026/10/04 19:46:08 INFO Vacuumed table table=pending_closures7552026/10/04 19:46:08 INFO Vacuumed table table=pending_objects7562026/10/04 19:46:08 INFO Vacuumed table table=multipart_uploads7572026/10/04 19:46:08 INFO Aborted multipart uploads count=0 kept=07582026/10/04 19:46:08 WARN Force mode enabled - objects will be deleted immediately without grace period7592026/10/04 19:46:08 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=07602026/10/04 19:46:08 INFO Vacuumed table table=pending_closures7612026/10/04 19:46:08 INFO Vacuumed table table=pending_objects7622026/10/04 19:46:08 INFO Vacuumed table table=closures7632026/10/04 19:46:08 INFO Vacuumed table table=multipart_uploads7642026/10/04 19:46:08 INFO Vacuumed table table=closures7652026/10/04 19:46:08 INFO Vacuumed table table=objects766--- PASS: TestGCMetrics (2.04s)767=== CONT TestClientFallsBackToClosures7682026/10/04 19:46:08 INFO Vacuumed table table=objects7692026/10/04 19:46:08 INFO Aborted multipart uploads count=0 kept=07702026/10/04 19:46:08 WARN Force mode enabled - objects will be deleted immediately without grace period7712026/10/04 19:46:08 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=07722026/10/04 19:46:08 INFO Vacuumed table table=pending_closures7732026/10/04 19:46:08 INFO Vacuumed table table=pending_objects7742026/10/04 19:46:08 INFO Vacuumed table table=multipart_uploads7752026/10/04 19:46:08 INFO Vacuumed table table=closures7762026/10/04 19:46:08 INFO Vacuumed table table=objects777--- PASS: TestPushDedupSurvivesConcurrentGC (2.24s)778=== CONT TestClientPushesUseOnePush7792026/10/04 19:46:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7802026/10/04 19:46:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjhmNTdlY2E2LTk2NWEtNGUzNy1hOTEyLTM1NzE2Y2YyMjRkYngxNzkxMTQzMTY3NjI5OTkzMDAw parts=127812026/10/04 19:46:09 INFO Received uploads request method=POST path=/api/pending_closures782--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.03s)783=== CONT TestPinProtectsFromGC784--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.13s)785=== CONT TestCompleteMultipartUnregistered786--- PASS: TestGCBugBareHashReferences (2.32s)787=== CONT TestService_verifyS3Integrity7882026/10/04 19:46:09 INFO lead: acquired remote=192.0.2.1:12347892026/10/04 19:46:09 INFO lead: acquired remote=192.0.2.1:12347902026/10/04 19:46:10 INFO Received push request method=POST path=/api/pushes7912026/10/04 19:46:10 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)7922026/10/04 19:46:10 INFO Uploading yl91zapdz9hmr3qdmsa5sr1nihbjv008-shared-dep (136B)7932026/10/04 19:46:10 INFO Uploading rxhdgmizbi2ig6509r3c4fy70pi2dhn1-a (248B)7942026/10/04 19:46:10 WARN Failed to register uploaded object key=38px3hzgb23m5n89ig963mz46n9ira1a.ls error="server returned 404: 404 page not found\n"7952026/10/04 19:46:10 WARN Failed to register uploaded object key=nar/0zqvjl6fd76ph2y0s5km919zxzwgm9sc8fg0bm7ang5z0j5mxj4m.nar.zst error="server returned 404: 404 page not found\n"7962026/10/04 19:46:10 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7972026/10/04 19:46:10 WARN Failed to register uploaded object key=rxhdgmizbi2ig6509r3c4fy70pi2dhn1.ls error="server returned 404: 404 page not found\n"7982026/10/04 19:46:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7992026/10/04 19:46:10 WARN Failed to register uploaded object key=yl91zapdz9hmr3qdmsa5sr1nihbjv008.ls error="server returned 404: 404 page not found\n"8002026/10/04 19:46:10 INFO Signed narinfos id=1 count=38012026/10/04 19:46:10 INFO Uploading 3 narinfos8022026/10/04 19:46:10 INFO Received uploads request method=POST path=/api/pending_closures8032026/10/04 19:46:10 WARN Failed to register uploaded object key=yl91zapdz9hmr3qdmsa5sr1nihbjv008.narinfo error="server returned 404: 404 page not found\n"8042026/10/04 19:46:10 WARN Failed to register uploaded object key=38px3hzgb23m5n89ig963mz46n9ira1a.narinfo error="server returned 404: 404 page not found\n"8052026/10/04 19:46:10 INFO Received complete push request method=POST path=/api/pushes/1/complete8062026/10/04 19:46:10 WARN Failed to register uploaded object key=rxhdgmizbi2ig6509r3c4fy70pi2dhn1.narinfo error="server returned 404: 404 page not found\n"8072026/10/04 19:46:10 INFO Upload complete. (95ms)808=== NAME TestClientPushesUseOnePush809 client_pushes_test.go:97: Retrieved narinfo from S3:810 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientPushesUseOnePush1310764700/001/store/yl91zapdz9hmr3qdmsa5sr1nihbjv008-shared-dep811 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst812 Compression: zstd813 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82814 NarSize: 136815 References: 816 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n817 client_pushes_test.go:97: Retrieved narinfo from S3:818 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientPushesUseOnePush1310764700/001/store/rxhdgmizbi2ig6509r3c4fy70pi2dhn1-a819 URL: nar/0zqvjl6fd76ph2y0s5km919zxzwgm9sc8fg0bm7ang5z0j5mxj4m.nar.zst820 Compression: zstd821 NarHash: sha256:0zqvjl6fd76ph2y0s5km919zxzwgm9sc8fg0bm7ang5z0j5mxj4m822 NarSize: 248823 References: /nix/var/nix/builds/nix-96338-3122596536/TestClientPushesUseOnePush1310764700/001/store/yl91zapdz9hmr3qdmsa5sr1nihbjv008-shared-dep824 CA: text:sha256:1p89pybxk118ykf0l8jcmi2d3hyz676iai8nwdkqkbxz0j3y4k5f825 client_pushes_test.go:97: Retrieved narinfo from S3:826 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientPushesUseOnePush1310764700/001/store/38px3hzgb23m5n89ig963mz46n9ira1a-b827 URL: nar/0zqvjl6fd76ph2y0s5km919zxzwgm9sc8fg0bm7ang5z0j5mxj4m.nar.zst828 Compression: zstd829 NarHash: sha256:0zqvjl6fd76ph2y0s5km919zxzwgm9sc8fg0bm7ang5z0j5mxj4m830 NarSize: 248831 References: /nix/var/nix/builds/nix-96338-3122596536/TestClientPushesUseOnePush1310764700/001/store/yl91zapdz9hmr3qdmsa5sr1nihbjv008-shared-dep832 CA: text:sha256:1p89pybxk118ykf0l8jcmi2d3hyz676iai8nwdkqkbxz0j3y4k5f833--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.91s)834=== CONT TestService_createPendingClosureHandler835--- PASS: TestClientPushesUseOnePush (1.60s)836=== CONT TestService_cleanupPendingClosuresHandler8372026/10/04 19:46:10 INFO Received uploads request method=POST path=/api/pending_closures8382026/10/04 19:46:10 INFO lead: released remote=192.0.2.1:1234839--- PASS: TestLeadEndsOnShutdown (3.29s)840=== CONT TestPush_SignsNarinfosOfItsPendingObjects8412026/10/04 19:46:10 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/04 19:46:10 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8432026/10/04 19:46:10 INFO Uploading g56xia19nackb8zga0bj5qmsqqp1sh0i-shared-dep (136B)8442026/10/04 19:46:10 INFO Uploading mbc39k59i2nf2pcc46baajnmzhjmmv18-b (248B)8452026/10/04 19:46:10 WARN Failed to register uploaded object key=mbc39k59i2nf2pcc46baajnmzhjmmv18.ls error="server returned 404: 404 page not found\n"8462026/10/04 19:46:10 WARN Failed to register uploaded object key=g56xia19nackb8zga0bj5qmsqqp1sh0i.ls error="server returned 404: 404 page not found\n"8472026/10/04 19:46:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8482026/10/04 19:46:10 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8492026/10/04 19:46:10 WARN Failed to register uploaded object key=nar/00hxzz8q00ihfjj1rb6z6pyzxg53mv4ibpzhh8a97mw53axwnwms.nar.zst error="server returned 404: 404 page not found\n"8502026/10/04 19:46:10 WARN Failed to register uploaded object key=6sp7l76ks2dd2nvdlq2xmbw806h2d3qn.ls error="server returned 404: 404 page not found\n"8512026/10/04 19:46:10 INFO Signed narinfos id=2 count=28522026/10/04 19:46:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8532026/10/04 19:46:10 INFO Signed narinfos id=1 count=28542026/10/04 19:46:10 INFO Uploading 4 narinfos8552026/10/04 19:46:10 WARN Failed to register uploaded object key=g56xia19nackb8zga0bj5qmsqqp1sh0i.narinfo error="server returned 404: 404 page not found\n"8562026/10/04 19:46:10 WARN Failed to register uploaded object key=6sp7l76ks2dd2nvdlq2xmbw806h2d3qn.narinfo error="server returned 404: 404 page not found\n"8572026/10/04 19:46:10 WARN Failed to register uploaded object key=mbc39k59i2nf2pcc46baajnmzhjmmv18.narinfo error="server returned 404: 404 page not found\n"8582026/10/04 19:46:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8592026/10/04 19:46:10 WARN Failed to register uploaded object key=g56xia19nackb8zga0bj5qmsqqp1sh0i.narinfo error="server returned 404: 404 page not found\n"8602026/10/04 19:46:10 INFO Completed upload id=18612026/10/04 19:46:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8622026/10/04 19:46:10 INFO Completed upload id=28632026/10/04 19:46:10 INFO Upload complete. (195ms)864=== NAME TestClientFallsBackToClosures865 client_pushes_test.go:112: Retrieved narinfo from S3:866 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientFallsBackToClosures800856199/001/store/g56xia19nackb8zga0bj5qmsqqp1sh0i-shared-dep867 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst868 Compression: zstd869 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82870 NarSize: 136871 References: 872 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n873 client_pushes_test.go:112: Retrieved narinfo from S3:874 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientFallsBackToClosures800856199/001/store/6sp7l76ks2dd2nvdlq2xmbw806h2d3qn-a875 URL: nar/00hxzz8q00ihfjj1rb6z6pyzxg53mv4ibpzhh8a97mw53axwnwms.nar.zst876 Compression: zstd877 NarHash: sha256:00hxzz8q00ihfjj1rb6z6pyzxg53mv4ibpzhh8a97mw53axwnwms878 NarSize: 248879 References: /nix/var/nix/builds/nix-96338-3122596536/TestClientFallsBackToClosures800856199/001/store/g56xia19nackb8zga0bj5qmsqqp1sh0i-shared-dep880 CA: text:sha256:0zczlv5ng1b285vknxlfpw5h33wml6ckkk01dfpqlwwcj0swqlam881 client_pushes_test.go:112: Retrieved narinfo from S3:882 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientFallsBackToClosures800856199/001/store/mbc39k59i2nf2pcc46baajnmzhjmmv18-b883 URL: nar/00hxzz8q00ihfjj1rb6z6pyzxg53mv4ibpzhh8a97mw53axwnwms.nar.zst884 Compression: zstd885 NarHash: sha256:00hxzz8q00ihfjj1rb6z6pyzxg53mv4ibpzhh8a97mw53axwnwms886 NarSize: 248887 References: /nix/var/nix/builds/nix-96338-3122596536/TestClientFallsBackToClosures800856199/001/store/g56xia19nackb8zga0bj5qmsqqp1sh0i-shared-dep888 CA: text:sha256:0zczlv5ng1b285vknxlfpw5h33wml6ckkk01dfpqlwwcj0swqlam889--- PASS: TestClientFallsBackToClosures (1.87s)890=== CONT TestRedundantMultipartUpload8912026/10/04 19:46:10 INFO lead: released remote=192.0.2.1:12348922026/10/04 19:46:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8932026/10/04 19:46:10 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst894--- PASS: TestCompleteMultipartUnregistered (1.58s)895=== CONT TestService_Rustfstest896=== NAME TestPinProtectsFromGC897 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-96338-3122596536/TestPinProtectsFromGC1940610611/001/store/glf7j5cy025xi3gpav1ygsp7s565kakk-pinned-file.txt898 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-96338-3122596536/TestPinProtectsFromGC1940610611/001/store/p0q72n22x7f99displybhwz7kbyr4xj7-unpinned-file.txt8992026/10/04 19:46:10 INFO lead: acquired remote=192.0.2.1:12349002026/10/04 19:46:10 INFO Received push request method=POST path=/api/pushes9012026/10/04 19:46:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9022026/10/04 19:46:10 INFO Uploading glf7j5cy025xi3gpav1ygsp7s565kakk-pinned-file.txt (128B)9032026/10/04 19:46:10 WARN Failed to register uploaded object key=glf7j5cy025xi3gpav1ygsp7s565kakk.ls error="server returned 404: 404 page not found\n"9042026/10/04 19:46:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9052026/10/04 19:46:10 INFO Signed narinfos id=1 count=19062026/10/04 19:46:10 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9072026/10/04 19:46:10 INFO Uploading 1 narinfos9082026/10/04 19:46:10 INFO Received complete push request method=POST path=/api/pushes/1/complete9092026/10/04 19:46:10 WARN Failed to register uploaded object key=glf7j5cy025xi3gpav1ygsp7s565kakk.narinfo error="server returned 404: 404 page not found\n"9102026/10/04 19:46:10 INFO Upload complete. (96ms)9112026/10/04 19:46:11 INFO Received push request method=POST path=/api/pushes9122026/10/04 19:46:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9132026/10/04 19:46:11 INFO Uploading p0q72n22x7f99displybhwz7kbyr4xj7-unpinned-file.txt (128B)9142026/10/04 19:46:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9152026/10/04 19:46:11 INFO Signed narinfos id=2 count=19162026/10/04 19:46:11 WARN Failed to register uploaded object key=p0q72n22x7f99displybhwz7kbyr4xj7.ls error="server returned 404: 404 page not found\n"9172026/10/04 19:46:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9182026/10/04 19:46:11 INFO Uploading 1 narinfos9192026/10/04 19:46:11 INFO Received complete push request method=POST path=/api/pushes/2/complete9202026/10/04 19:46:11 WARN Failed to register uploaded object key=p0q72n22x7f99displybhwz7kbyr4xj7.narinfo error="server returned 404: 404 page not found\n"9212026/10/04 19:46:11 INFO Upload complete. (103ms)9222026/10/04 19:46:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures9232026/10/04 19:46:11 INFO Garbage collection started9242026/10/04 19:46:11 INFO Aborted multipart uploads count=0 kept=09252026/10/04 19:46:11 WARN Force mode enabled - objects will be deleted immediately without grace period9262026/10/04 19:46:11 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=09272026/10/04 19:46:11 INFO Vacuumed table table=pending_closures9282026/10/04 19:46:11 INFO Vacuumed table table=pending_objects9292026/10/04 19:46:11 INFO Vacuumed table table=multipart_uploads9302026/10/04 19:46:11 INFO Vacuumed table table=closures9312026/10/04 19:46:11 INFO Vacuumed table table=objects9322026/10/04 19:46:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9332026/10/04 19:46:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LmQ0N2RhMGU4LTczZDktNGZmZi1iMDBlLTc3OGJmMzVjZmFiZXgxNzkxMTQzMTcwMzk0MDkyMDAw parts=109342026/10/04 19:46:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9352026/10/04 19:46:11 INFO Completed upload id=19362026/10/04 19:46:11 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/04 19:46:11 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/04 19:46:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9392026/10/04 19:46:11 WARN Found objects in DB but missing from S3, will re-upload count=1940--- PASS: TestService_verifyS3Integrity (2.02s)941=== CONT TestPresignedUploadRegisteredBeforeCommit9422026/10/04 19:46:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9432026/10/04 19:46:11 INFO Aborted multipart uploads count=0 kept=09442026/10/04 19:46:11 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/04 19:46:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9462026/10/04 19:46:11 INFO Aborted multipart uploads count=1 kept=09472026/10/04 19:46:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9482026-10-04 19:46:11.529 UTC [96552] ERROR: Closure does not exist: id=19492026-10-04 19:46:11.529 UTC [96552] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9502026-10-04 19:46:11.529 UTC [96552] STATEMENT: -- name: CommitPendingClosure :exec951 SELECT commit_pending_closure($1::bigint)952 953--- PASS: TestService_cleanupPendingClosuresHandler (1.09s)954=== CONT TestPendingClosureWriteTimeout955=== RUN TestPendingClosureWriteTimeout/empty956=== PAUSE TestPendingClosureWriteTimeout/empty957=== RUN TestPendingClosureWriteTimeout/400_objects958=== PAUSE TestPendingClosureWriteTimeout/400_objects959=== RUN TestPendingClosureWriteTimeout/670k_objects960=== PAUSE TestPendingClosureWriteTimeout/670k_objects961=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline962=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline963=== CONT TestUploadHandlersRejectInvalidKeys964=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info965=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info966=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal967=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal968=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key969=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key970=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key971=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key972=== CONT TestIsValidUploadKey973=== RUN TestIsValidUploadKey/narinfo974=== PAUSE TestIsValidUploadKey/narinfo975=== RUN TestIsValidUploadKey/nar_zst976=== PAUSE TestIsValidUploadKey/nar_zst977=== RUN TestIsValidUploadKey/nar_xz978=== PAUSE TestIsValidUploadKey/nar_xz979=== RUN TestIsValidUploadKey/nar_plain980=== PAUSE TestIsValidUploadKey/nar_plain981=== RUN TestIsValidUploadKey/listing982=== PAUSE TestIsValidUploadKey/listing983=== RUN TestIsValidUploadKey/build_log984=== PAUSE TestIsValidUploadKey/build_log985=== RUN TestIsValidUploadKey/build_log_home-manager_file986=== PAUSE TestIsValidUploadKey/build_log_home-manager_file987=== RUN TestIsValidUploadKey/build_log_plus_in_name988=== PAUSE TestIsValidUploadKey/build_log_plus_in_name989=== RUN TestIsValidUploadKey/build_log_question_mark990=== PAUSE TestIsValidUploadKey/build_log_question_mark991=== RUN TestIsValidUploadKey/build_log_equals992=== PAUSE TestIsValidUploadKey/build_log_equals993=== RUN TestIsValidUploadKey/realisation994=== PAUSE TestIsValidUploadKey/realisation995=== RUN TestIsValidUploadKey/realisation_plus_in_output996=== PAUSE TestIsValidUploadKey/realisation_plus_in_output997=== RUN TestIsValidUploadKey/nix-cache-info998=== PAUSE TestIsValidUploadKey/nix-cache-info999=== RUN TestIsValidUploadKey/index.html1000=== PAUSE TestIsValidUploadKey/index.html1001=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1002=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1003=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1004=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1005=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1006=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1007=== RUN TestIsValidUploadKey/traversal1008=== PAUSE TestIsValidUploadKey/traversal1009=== RUN TestIsValidUploadKey/traversal_nar1010=== PAUSE TestIsValidUploadKey/traversal_nar1011=== RUN TestIsValidUploadKey/absolute1012=== PAUSE TestIsValidUploadKey/absolute1013=== RUN TestIsValidUploadKey/empty_key1014=== PAUSE TestIsValidUploadKey/empty_key1015=== RUN TestIsValidUploadKey/unknown_type1016=== PAUSE TestIsValidUploadKey/unknown_type1017=== CONT TestGCTaskStore_GetEmpty1018--- PASS: TestGCTaskStore_GetEmpty (0.00s)1019=== CONT TestClientSharedPathCommittedMidPush10202026/10/04 19:46:11 INFO Received push request method=POST path=/api/pushes10212026/10/04 19:46:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/04 19:46:11 INFO Signed narinfos id=1 count=11023--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.27s)1024=== CONT TestService_NativeMTLS10252026/10/04 19:46:11 INFO lead: released remote=192.0.2.1:12341026--- PASS: TestLeadElectsOneAndHandsOver (4.04s)1027=== CONT TestClientWithDependencies10282026/10/04 19:46:11 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/04 19:46:11 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/04 19:46:12 INFO Received uploads request method=POST path=/api/pending_closures10312026/10/04 19:46:12 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/04 19:46:12 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/04 19:46:12 WARN Rate limiter enabled after throttle name=s3-test rate=510342026/10/04 19:46:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1035=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1036 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101037 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001038--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.12s)1039=== CONT TestMetricsInventory1040--- PASS: TestService_Rustfstest (1.56s)1041=== CONT TestClientMultipleUploads10422026/10/04 19:46:12 INFO Received uploads request method=POST path=/api/pending_closures10432026/10/04 19:46:12 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10442026/10/04 19:46:12 INFO Received uploads request method=POST path=/api/pending_closures1045--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.57s)1046=== CONT TestNARDeduplicationMetadataUploadBug10472026/10/04 19:46:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=010482026/10/04 19:46:13 INFO Received create pin request method=POST path=/api/pins/myapp10492026/10/04 19:46:13 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-96338-3122596536/TestPinProtectsFromGC1940610611/001/store/glf7j5cy025xi3gpav1ygsp7s565kakk-pinned-file.txt narinfo_key=glf7j5cy025xi3gpav1ygsp7s565kakk.narinfo10502026/10/04 19:46:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures10512026/10/04 19:46:13 INFO Garbage collection started10522026/10/04 19:46:13 INFO Aborted multipart uploads count=0 kept=010532026/10/04 19:46:13 WARN Force mode enabled - objects will be deleted immediately without grace period10542026/10/04 19:46:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010552026/10/04 19:46:13 INFO Vacuumed table table=pending_closures10562026/10/04 19:46:13 INFO Vacuumed table table=pending_objects10572026/10/04 19:46:13 INFO Vacuumed table table=multipart_uploads10582026/10/04 19:46:13 INFO Vacuumed table table=closures10592026/10/04 19:46:13 INFO Vacuumed table table=objects10602026/10/04 19:46:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/10/04 19:46:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10622026/10/04 19:46:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjUwZjA4ZGUxLThlNWUtNDFiNi04ODZiLTVhMmE5YmVlMjY4ZHgxNzkxMTQzMTcyMTQ5Nzk3MDAw parts=1010632026/10/04 19:46:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10642026/10/04 19:46:13 INFO Completed upload id=110652026/10/04 19:46:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010662026/10/04 19:46:13 INFO Received uploads request method=POST path=/api/pending_closures10672026/10/04 19:46:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures10682026/10/04 19:46:13 INFO Aborted multipart uploads count=0 kept=010692026/10/04 19:46:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010702026/10/04 19:46:13 INFO Vacuumed table table=pending_closures10712026/10/04 19:46:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LmU0MzdlYTE5LTNjNzctNGRjYS04ZjAzLTZiNzI5NjVhZTcyOXgxNzkxMTQzMTcxOTIyNTYxMDAw parts=1210722026/10/04 19:46:13 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/04 19:46:13 INFO Vacuumed table table=pending_objects10742026/10/04 19:46:13 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/04 19:46:13 INFO Vacuumed table table=multipart_uploads10762026/10/04 19:46:13 INFO Vacuumed table table=closures10772026/10/04 19:46:13 INFO Vacuumed table table=objects10782026/10/04 19:46:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001079--- PASS: TestService_createPendingClosureHandler (3.28s)1080=== CONT TestClientIntegration10812026/10/04 19:46:13 INFO Received push request method=POST path=/api/pushes10822026/10/04 19:46:13 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10832026/10/04 19:46:13 INFO Uploading nkisz15w6622s28sdnwchp772dgcc6w7-top (256B)10842026/10/04 19:46:13 INFO Uploading rk062hmgc5n1p22117g4r2piii97hc8d-shared-dep (136B)10852026/10/04 19:46:13 WARN Failed to register uploaded object key=rk062hmgc5n1p22117g4r2piii97hc8d.ls error="server returned 404: 404 page not found\n"10862026/10/04 19:46:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10872026/10/04 19:46:13 WARN Failed to register uploaded object key=nkisz15w6622s28sdnwchp772dgcc6w7.ls error="server returned 404: 404 page not found\n"10882026/10/04 19:46:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10892026/10/04 19:46:13 WARN Failed to register uploaded object key=nar/0nx3xzhg70i44f2gwjisvyg2k6hpr6cqhivqlriihgxq39i89vxn.nar.zst error="server returned 404: 404 page not found\n"10902026/10/04 19:46:13 INFO Signed narinfos id=1 count=210912026/10/04 19:46:13 INFO Uploading 2 narinfos10922026/10/04 19:46:13 WARN Failed to register uploaded object key=rk062hmgc5n1p22117g4r2piii97hc8d.narinfo error="server returned 404: 404 page not found\n"10932026/10/04 19:46:13 INFO Received complete push request method=POST path=/api/pushes/1/complete10942026/10/04 19:46:13 WARN Failed to register uploaded object key=nkisz15w6622s28sdnwchp772dgcc6w7.narinfo error="server returned 404: 404 page not found\n"10952026/10/04 19:46:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10962026/10/04 19:46:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1097--- PASS: TestService_NativeMTLS (2.03s)1098=== CONT TestCreatePendingClosureRejectsOversizedNAR10992026/10/04 19:46:13 INFO Received uploads request method=POST path=/api/pending_closures1100--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1101=== CONT TestCacheConfigHandlerMaxNarSize1102--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1103=== CONT TestGenerateLandingPage1104--- PASS: TestGenerateLandingPage (0.00s)1105=== CONT TestService_readinessHandler11062026/10/04 19:46:13 INFO Upload complete. (171ms)1107=== NAME TestClientSharedPathCommittedMidPush1108 client_integration_test.go:680: Retrieved narinfo from S3:1109 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientSharedPathCommittedMidPush4266004662/001/store/rk062hmgc5n1p22117g4r2piii97hc8d-shared-dep1110 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1111 Compression: zstd1112 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821113 NarSize: 1361114 References: 1115 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1116 client_integration_test.go:680: Retrieved narinfo from S3:1117 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientSharedPathCommittedMidPush4266004662/001/store/nkisz15w6622s28sdnwchp772dgcc6w7-top1118 URL: nar/0nx3xzhg70i44f2gwjisvyg2k6hpr6cqhivqlriihgxq39i89vxn.nar.zst1119 Compression: zstd1120 NarHash: sha256:0nx3xzhg70i44f2gwjisvyg2k6hpr6cqhivqlriihgxq39i89vxn1121 NarSize: 2561122 References: /nix/var/nix/builds/nix-96338-3122596536/TestClientSharedPathCommittedMidPush4266004662/001/store/rk062hmgc5n1p22117g4r2piii97hc8d-shared-dep1123 CA: text:sha256:0ai934dn08mhzssiw8cxhw507zhkjrifx711azw6jxp6fdcqbx1a1124--- PASS: TestClientSharedPathCommittedMidPush (2.35s)1125=== CONT TestService_healthCheckHandler1126=== NAME TestClientWithDependencies1127 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-96338-3122596536/TestClientWithDependencies2398648492/001/store/q4byx0l2l27pj3wydc8ny6h62hv8hahk-test-script1128--- PASS: TestConnectWaitsForAPeerMigration (6.69s)1129=== CONT TestGracefulShutdownDrainsInflight11302026/10/04 19:46:14 INFO Starting HTTP server address=127.0.0.1:6542511312026/10/04 19:46:14 INFO Shutdown signal received, draining in-flight requests timeout=10s1132=== NAME TestClientWithDependencies1133 client_integration_test.go:615: Found 1 dependencies (including self)1134--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1135=== CONT TestGCTaskStore_Fail1136--- PASS: TestGCTaskStore_Fail (0.00s)1137=== CONT TestGCTaskStore_PhaseUpdates1138--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1139=== CONT TestGCTaskStore_CompletedAllowsNewTask1140--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1141=== CONT TestGCTaskStore_GetReturnsLatest1142--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1143=== CONT TestProxyWriteTimeout1144=== RUN TestProxyWriteTimeout/narinfo1145=== PAUSE TestProxyWriteTimeout/narinfo1146=== RUN TestProxyWriteTimeout/1_GiB_nar1147=== PAUSE TestProxyWriteTimeout/1_GiB_nar1148=== RUN TestProxyWriteTimeout/10_GiB_nar1149=== PAUSE TestProxyWriteTimeout/10_GiB_nar1150=== RUN TestProxyWriteTimeout/unknown_size1151=== PAUSE TestProxyWriteTimeout/unknown_size1152=== CONT TestService_RequireScope_OIDC1153=== NAME TestClientMultipleUploads1154 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-96338-3122596536/TestClientMultipleUploads394585517/001/store/bh6gmaysgvpsa42mxdqwmzc7np54j556-test-file-0.txt11552026/10/04 19:46:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65428/oidc11562026/10/04 19:46:14 INFO Received push request method=POST path=/api/pushes1157 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-96338-3122596536/TestClientMultipleUploads394585517/001/store/yhac2hfvxjmajlfs35dvh9i4x12fhlcw-test-file-1.txt1158--- PASS: TestMetricsInventory (2.75s)1159=== CONT TestCacheConfigHandler1160=== RUN TestCacheConfigHandler/full_config,_no_issuer1161=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1162=== RUN TestCacheConfigHandler/no_cache_url_configured1163=== PAUSE TestCacheConfigHandler/no_cache_url_configured1164=== RUN TestCacheConfigHandler/no_signing_keys1165=== PAUSE TestCacheConfigHandler/no_signing_keys1166=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1167=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1168=== CONT TestCacheStatsHandler11692026/10/04 19:46:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11702026/10/04 19:46:14 INFO Uploading q4byx0l2l27pj3wydc8ny6h62hv8hahk-test-script (136B)11712026/10/04 19:46:15 WARN Failed to register uploaded object key=q4byx0l2l27pj3wydc8ny6h62hv8hahk.ls error="server returned 404: 404 page not found\n"11722026/10/04 19:46:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11732026/10/04 19:46:15 WARN Failed to register uploaded object key=log/313q8sjsriv56izdab6z0lxdpxjy4xcd-test-script.drv error="server returned 404: 404 page not found\n"11742026/10/04 19:46:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11752026/10/04 19:46:15 INFO Signed narinfos id=1 count=111762026/10/04 19:46:15 INFO Uploading 1 narinfos11772026/10/04 19:46:15 INFO Received complete push request method=POST path=/api/pushes/1/complete11782026/10/04 19:46:15 WARN Failed to register uploaded object key=q4byx0l2l27pj3wydc8ny6h62hv8hahk.narinfo error="server returned 404: 404 page not found\n"11792026/10/04 19:46:15 INFO Upload complete. (113ms)1180=== NAME TestClientWithDependencies1181 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-96338-3122596536/TestClientWithDependencies2398648492/001/store) requires matching store prefix1182=== NAME TestClientMultipleUploads1183 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-96338-3122596536/TestClientMultipleUploads394585517/001/store/hcby2qi16vmgqcbzx6qp23hf1k2xq6ng-test-file-2.txt1184--- PASS: TestClientWithDependencies (3.20s)1185=== CONT TestClientErrorHandling1186=== RUN TestClientErrorHandling/InvalidStorePath1187=== PAUSE TestClientErrorHandling/InvalidStorePath1188=== RUN TestClientErrorHandling/InvalidAuthToken1189=== PAUSE TestClientErrorHandling/InvalidAuthToken1190=== RUN TestClientErrorHandling/ServerNotAvailable1191=== PAUSE TestClientErrorHandling/ServerNotAvailable1192=== CONT TestClientCADerivations11932026/10/04 19:46:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11942026/10/04 19:46:15 INFO Received push request method=POST path=/api/pushes11952026/10/04 19:46:15 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjkxZGMxYjU5LWM2OGMtNDYyYy1hMDQwLTQ0YzY3YzMxMmVhN3gxNzkxMTQzMTczNTkwMDM4MDAw error="Get \"http://127.0.0.1:1/bucket27/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11962026/10/04 19:46:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmE5MTMxZTktNzkwMy00Nzk2LTllNGYtYzY1YjczZDYxMjc3LjViZDc2YmNkLWJhYWQtNDM2ZC1hN2QwLTc0OTc3Y2FiNTA0N3gxNzkxMTQzMTczNTM4MTg0MDAw parts=1211972026/10/04 19:46:15 INFO Received cleanup request method=DELETE path=/api/pending_closures1198=== NAME TestPinProtectsFromGC1199 client_integration_test.go:840: Pin successfully protected closure from garbage collection12002026/10/04 19:46:15 INFO Aborted multipart uploads count=1 kept=012012026/10/04 19:46:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12022026/10/04 19:46:15 INFO Uploading yhac2hfvxjmajlfs35dvh9i4x12fhlcw-test-file-1.txt (160B)12032026/10/04 19:46:15 INFO Uploading hcby2qi16vmgqcbzx6qp23hf1k2xq6ng-test-file-2.txt (160B)12042026/10/04 19:46:15 INFO Uploading bh6gmaysgvpsa42mxdqwmzc7np54j556-test-file-0.txt (160B)1205--- PASS: TestRedundantMultipartUpload (4.51s)1206=== CONT TestParseSize1207--- PASS: TestParseSize (0.00s)1208=== CONT TestSkippedUploadsHandler12092026/10/04 19:46:15 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001210--- PASS: TestSkippedUploadsHandler (0.00s)1211=== CONT TestReadProxyNarinfoAlreadyDecompressed12122026/10/04 19:46:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12132026/10/04 19:46:15 WARN Failed to register uploaded object key=yhac2hfvxjmajlfs35dvh9i4x12fhlcw.ls error="server returned 404: 404 page not found\n"12142026/10/04 19:46:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12152026/10/04 19:46:15 WARN Failed to register uploaded object key=hcby2qi16vmgqcbzx6qp23hf1k2xq6ng.ls error="server returned 404: 404 page not found\n"12162026/10/04 19:46:15 WARN Failed to register uploaded object key=bh6gmaysgvpsa42mxdqwmzc7np54j556.ls error="server returned 404: 404 page not found\n"12172026/10/04 19:46:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12182026/10/04 19:46:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12192026/10/04 19:46:15 INFO Signed narinfos id=1 count=312202026/10/04 19:46:15 INFO Uploading 3 narinfos12212026/10/04 19:46:15 WARN Failed to register uploaded object key=yhac2hfvxjmajlfs35dvh9i4x12fhlcw.narinfo error="server returned 404: 404 page not found\n"12222026/10/04 19:46:15 INFO Received complete push request method=POST path=/api/pushes/1/complete1223--- PASS: TestPinProtectsFromGC (6.05s)1224=== CONT TestReadRedirectUsesPublicS3URL12252026/10/04 19:46:15 WARN Failed to register uploaded object key=hcby2qi16vmgqcbzx6qp23hf1k2xq6ng.narinfo error="server returned 404: 404 page not found\n"12262026/10/04 19:46:15 WARN Failed to register uploaded object key=bh6gmaysgvpsa42mxdqwmzc7np54j556.narinfo error="server returned 404: 404 page not found\n"12272026/10/04 19:46:15 INFO Upload complete. (130ms)1228=== NAME TestClientMultipleUploads1229 client_integration_test.go:369: Uploaded 3 paths in 165.654625ms1230--- PASS: TestClientMultipleUploads (2.95s)1231=== CONT TestReadProxyRangeRequest1232=== NAME TestNARDeduplicationMetadataUploadBug1233 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-96338-3122596536/TestNARDeduplicationMetadataUploadBug771505946/001/store/q892rm42pb39q0sfli8if91n7sp10049-file1.txt12342026/10/04 19:46:15 INFO Received push request method=POST path=/api/pushes12352026/10/04 19:46:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12362026/10/04 19:46:15 INFO Uploading q892rm42pb39q0sfli8if91n7sp10049-file1.txt (160B)12372026/10/04 19:46:15 WARN Failed to register uploaded object key=q892rm42pb39q0sfli8if91n7sp10049.ls error="server returned 404: 404 page not found\n"12382026/10/04 19:46:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12392026/10/04 19:46:15 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12402026/10/04 19:46:15 INFO Signed narinfos id=1 count=112412026/10/04 19:46:15 INFO Uploading 1 narinfos12422026/10/04 19:46:15 INFO Received complete push request method=POST path=/api/pushes/1/complete12432026/10/04 19:46:15 WARN Failed to register uploaded object key=q892rm42pb39q0sfli8if91n7sp10049.narinfo error="server returned 404: 404 page not found\n"12442026/10/04 19:46:15 INFO Upload complete. (94ms)1245 metadata_upload_test.go:54: Retrieved narinfo from S3:1246 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestNARDeduplicationMetadataUploadBug771505946/001/store/q892rm42pb39q0sfli8if91n7sp10049-file1.txt1247 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1248 Compression: zstd1249 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1250 NarSize: 1601251 References: 1252 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1253 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1254 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1255 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1256 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-96338-3122596536/TestNARDeduplicationMetadataUploadBug771505946/001/store/cywmfwvx2f8fl7hg724dr2qb58jmfibs-file2.txt12572026/10/04 19:46:15 INFO Received push request method=POST path=/api/pushes12582026/10/04 19:46:15 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12592026/10/04 19:46:15 WARN Failed to register uploaded object key=cywmfwvx2f8fl7hg724dr2qb58jmfibs.ls error="server returned 404: 404 page not found\n"12602026/10/04 19:46:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12612026/10/04 19:46:15 INFO Signed narinfos id=2 count=112622026/10/04 19:46:15 INFO Uploading 1 narinfos12632026/10/04 19:46:16 INFO Received complete push request method=POST path=/api/pushes/2/complete12642026/10/04 19:46:16 WARN Failed to register uploaded object key=cywmfwvx2f8fl7hg724dr2qb58jmfibs.narinfo error="server returned 404: 404 page not found\n"12652026/10/04 19:46:16 INFO Upload complete. (90ms)1266 metadata_upload_test.go:76: Retrieved narinfo from S3:1267 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestNARDeduplicationMetadataUploadBug771505946/001/store/cywmfwvx2f8fl7hg724dr2qb58jmfibs-file2.txt1268 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1269 Compression: zstd1270 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1271 NarSize: 1601272 References: 1273 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1274 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1275 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1276 {"version":1,"root":{"type":"regular","size":44}}1277--- PASS: TestNARDeduplicationMetadataUploadBug (3.20s)1278=== CONT TestReadRedirectKeepsNarinfoProxied1279=== NAME TestClientIntegration1280 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-96338-3122596536/TestClientIntegration72403596/002/store/8wlhrnz74rgd4simsjkgp6b2jpr4bf5m-test-file.txt12812026/10/04 19:46:16 WARN readiness check failed error="closed pool"1282--- PASS: TestService_readinessHandler (2.37s)1283=== CONT TestReadRedirectNar12842026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes12852026/10/04 19:46:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12862026/10/04 19:46:16 INFO Uploading 8wlhrnz74rgd4simsjkgp6b2jpr4bf5m-test-file.txt (152B)12872026/10/04 19:46:16 WARN Failed to register uploaded object key=8wlhrnz74rgd4simsjkgp6b2jpr4bf5m.ls error="server returned 404: 404 page not found\n"12882026/10/04 19:46:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/04 19:46:16 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12902026/10/04 19:46:16 INFO Signed narinfos id=1 count=112912026/10/04 19:46:16 INFO Uploading 1 narinfos12922026/10/04 19:46:16 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/04 19:46:16 WARN Failed to register uploaded object key=8wlhrnz74rgd4simsjkgp6b2jpr4bf5m.narinfo error="server returned 404: 404 page not found\n"12942026/10/04 19:46:16 INFO Upload complete. (123ms)12952026/10/04 19:46:16 INFO All 1 paths already cached1296=== NAME TestClientIntegration1297 client_integration_test.go:312: Retrieved narinfo from S3:1298 StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientIntegration72403596/002/store/8wlhrnz74rgd4simsjkgp6b2jpr4bf5m-test-file.txt1299 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1300 Compression: zstd1301 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11302 NarSize: 1521303 References: 1304 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11305 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1306 client_integration_test.go:313: Decompressed .ls content (64 bytes):1307 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1308 client_integration_test.go:316: Testing garbage collection...13092026/10/04 19:46:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures13102026/10/04 19:46:16 INFO Garbage collection started13112026/10/04 19:46:16 INFO Aborted multipart uploads count=0 kept=013122026/10/04 19:46:16 WARN Force mode enabled - objects will be deleted immediately without grace period1313--- PASS: TestService_healthCheckHandler (2.55s)1314=== CONT TestReadProxyDisabled13152026/10/04 19:46:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013162026/10/04 19:46:16 INFO Vacuumed table table=pending_closures13172026/10/04 19:46:16 INFO Vacuumed table table=pending_objects13182026/10/04 19:46:16 INFO Vacuumed table table=multipart_uploads13192026/10/04 19:46:16 INFO Vacuumed table table=closures13202026/10/04 19:46:16 INFO Vacuumed table table=objects1321=== RUN TestService_RequireScope_OIDC/builder_may_write1322=== PAUSE TestService_RequireScope_OIDC/builder_may_write1323=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1324=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1325=== RUN TestService_RequireScope_OIDC/ops_may_admin1326=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1327=== RUN TestService_RequireScope_OIDC/ops_may_not_write1328=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1329=== RUN TestService_RequireScope_OIDC/reader_may_not_write1330=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1331=== RUN TestService_RequireScope_OIDC/static_token_may_admin1332=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1333=== RUN TestService_RequireScope_OIDC/static_token_may_write1334=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1335=== RUN TestService_RequireScope_OIDC/reader_may_read1336=== PAUSE TestService_RequireScope_OIDC/reader_may_read1337=== RUN TestService_RequireScope_OIDC/writer_implies_read1338=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1339=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1340=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1341=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1342=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1343=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1344=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1345=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1346=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1347=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1348=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1349=== CONT TestService_AuthMiddleware_OIDC13502026/10/04 19:46:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65488/oidc1351--- PASS: TestCacheStatsHandler (1.88s)1352=== CONT TestReadProxyRootRedirectsToIndexHTML1353--- PASS: TestReadRedirectUsesPublicS3URL (2.07s)1354=== CONT TestReadProxyConditionalGet1355--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.26s)1356=== CONT TestReadProxyOutlastsServerWriteTimeout1357=== NAME TestClientCADerivations1358 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-96338-3122596536/TestClientCADerivations1562012576/001/store/p3kjsc1afycsypnw5hp8q7cp22qkhdmq-ca-test1359 client_ca_test.go:139: Found 1 dependencies (including self)13602026/10/04 19:46:17 INFO Received push request method=POST path=/api/pushes1361--- PASS: TestReadProxyRangeRequest (2.29s)1362=== CONT TestReadProxyHead13632026/10/04 19:46:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13642026/10/04 19:46:17 INFO Uploading p3kjsc1afycsypnw5hp8q7cp22qkhdmq-ca-test (144B)13652026/10/04 19:46:17 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13662026/10/04 19:46:17 WARN Failed to register uploaded object key=p3kjsc1afycsypnw5hp8q7cp22qkhdmq.ls error="server returned 404: 404 page not found\n"13672026/10/04 19:46:17 WARN Failed to register uploaded object key=log/vb300ann0k5xsylv52c3sinnh3i8cq1b-ca-test.drv error="server returned 404: 404 page not found\n"13682026/10/04 19:46:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13692026/10/04 19:46:17 INFO Signed narinfos id=1 count=113702026/10/04 19:46:17 INFO Uploading 1 narinfos13712026/10/04 19:46:17 INFO Received complete push request method=POST path=/api/pushes/1/complete13722026/10/04 19:46:17 WARN Failed to register uploaded object key=p3kjsc1afycsypnw5hp8q7cp22qkhdmq.narinfo error="server returned 404: 404 page not found\n"13732026/10/04 19:46:17 INFO Upload complete. (165ms)1374=== NAME TestClientCADerivations1375 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-96338-3122596536/TestClientCADerivations1562012576/001/store/p3kjsc1afycsypnw5hp8q7cp22qkhdmq-ca-test1376 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1377 Compression: zstd1378 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1379 NarSize: 1441380 References: 1381 Deriver: /nix/var/nix/builds/nix-96338-3122596536/TestClientCADerivations1562012576/001/store/vb300ann0k5xsylv52c3sinnh3i8cq1b-ca-test.drv1382 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1383 client_ca_test.go:185: Checking for realisation files in S3...1384 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1385 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1386 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket42?endpoint=http://localhost:65255®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-96338-3122596536/TestClientCADerivations1562012576/001/store'1387 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11388--- PASS: TestClientCADerivations (2.70s)1389=== CONT TestReadProxyInvalidPath1390--- PASS: TestReadRedirectKeepsNarinfoProxied (1.78s)1391=== CONT TestReadProxy4041392--- PASS: TestReadRedirectNar (1.82s)1393=== CONT TestReadProxyNarStreaming1394--- PASS: TestReadProxyDisabled (1.74s)1395=== CONT TestService_ReadAuthMiddleware13962026/10/04 19:46:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01397=== NAME TestClientIntegration1398 client_integration_test.go:323: Objects in database after GC:1399=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1400=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1401=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1402=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1403=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1404=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1405=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1406=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1407=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1408=== NAME TestClientIntegration1409 client_integration_test.go:323: Successfully deleted all objects with GC --force1410--- PASS: TestClientIntegration (4.74s)1411=== CONT TestCreatePin_ReservedPins14122026/10/04 19:46:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65534/oidc1413--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.70s)1414=== CONT TestReadProxyNarinfo1415--- PASS: TestReadProxyConditionalGet (1.48s)1416=== CONT TestIsValidCachePath1417=== RUN TestIsValidCachePath/narinfo1418=== PAUSE TestIsValidCachePath/narinfo1419=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1420=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1421=== RUN TestIsValidCachePath/nar_zst1422=== PAUSE TestIsValidCachePath/nar_zst1423=== RUN TestIsValidCachePath/nar_xz1424=== PAUSE TestIsValidCachePath/nar_xz1425=== RUN TestIsValidCachePath/nar_bz21426=== PAUSE TestIsValidCachePath/nar_bz21427=== RUN TestIsValidCachePath/nar_uncompressed1428=== PAUSE TestIsValidCachePath/nar_uncompressed1429=== RUN TestIsValidCachePath/ls1430=== PAUSE TestIsValidCachePath/ls1431=== RUN TestIsValidCachePath/log1432=== PAUSE TestIsValidCachePath/log1433=== RUN TestIsValidCachePath/realisation1434=== PAUSE TestIsValidCachePath/realisation1435=== RUN TestIsValidCachePath/nix-cache-info1436=== PAUSE TestIsValidCachePath/nix-cache-info1437=== RUN TestIsValidCachePath/index.html1438=== PAUSE TestIsValidCachePath/index.html1439=== RUN TestIsValidCachePath/traversal_parent1440=== PAUSE TestIsValidCachePath/traversal_parent1441=== RUN TestIsValidCachePath/traversal_in_middle1442=== PAUSE TestIsValidCachePath/traversal_in_middle1443=== RUN TestIsValidCachePath/invalid_char_e1444=== PAUSE TestIsValidCachePath/invalid_char_e1445=== RUN TestIsValidCachePath/invalid_char_u1446=== PAUSE TestIsValidCachePath/invalid_char_u1447=== RUN TestIsValidCachePath/random_path1448=== PAUSE TestIsValidCachePath/random_path1449=== RUN TestIsValidCachePath/empty1450=== PAUSE TestIsValidCachePath/empty1451=== RUN TestIsValidCachePath/leading_slash1452=== PAUSE TestIsValidCachePath/leading_slash1453=== RUN TestIsValidCachePath/wrong_extension1454=== PAUSE TestIsValidCachePath/wrong_extension1455=== RUN TestIsValidCachePath/short_hash1456=== PAUSE TestIsValidCachePath/short_hash1457=== CONT TestService_ReadScope_PublicByDefault1458--- PASS: TestReadProxyHead (1.64s)1459=== CONT TestGetExistingObjectsLocksRows1460--- PASS: TestReadProxy404 (1.71s)1461=== CONT TestProxyHeadersOnlyTrustedOnSocket1462--- PASS: TestReadProxyInvalidPath (1.94s)1463=== CONT TestParseSingleRange1464=== RUN TestParseSingleRange/none1465=== PAUSE TestParseSingleRange/none1466=== RUN TestParseSingleRange/unknown_unit1467=== PAUSE TestParseSingleRange/unknown_unit1468=== RUN TestParseSingleRange/multi-range_ignored1469=== PAUSE TestParseSingleRange/multi-range_ignored1470=== RUN TestParseSingleRange/malformed_no_dash1471=== PAUSE TestParseSingleRange/malformed_no_dash1472=== RUN TestParseSingleRange/malformed_both_empty1473=== PAUSE TestParseSingleRange/malformed_both_empty1474=== RUN TestParseSingleRange/malformed_end_before_start1475=== PAUSE TestParseSingleRange/malformed_end_before_start1476=== RUN TestParseSingleRange/closed1477=== PAUSE TestParseSingleRange/closed1478=== RUN TestParseSingleRange/open-ended1479=== PAUSE TestParseSingleRange/open-ended1480=== RUN TestParseSingleRange/end_clamped_to_size1481=== PAUSE TestParseSingleRange/end_clamped_to_size1482=== RUN TestParseSingleRange/suffix1483=== PAUSE TestParseSingleRange/suffix1484=== RUN TestParseSingleRange/suffix_exceeds_size1485=== PAUSE TestParseSingleRange/suffix_exceeds_size1486=== RUN TestParseSingleRange/single_byte1487=== PAUSE TestParseSingleRange/single_byte1488=== RUN TestParseSingleRange/start_past_EOF1489=== PAUSE TestParseSingleRange/start_past_EOF1490=== RUN TestParseSingleRange/start_far_past_EOF1491=== PAUSE TestParseSingleRange/start_far_past_EOF1492=== CONT TestPush_RejectsBadRequests1493--- PASS: TestReadProxyNarStreaming (1.98s)1494=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1495--- PASS: TestService_ReadAuthMiddleware (2.00s)1496=== CONT TestGCTaskStore_ConflictDifferentParams1497--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1498=== CONT TestGCEndsOnShutdown14992026/10/04 19:46:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15002026/10/04 19:46:20 WARN mTLS auth: bound subjects configured but subject DN unavailable15012026/10/04 19:46:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1502--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.01s)1503=== CONT TestGCTaskStore_DeduplicateSameParams1504--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1505=== CONT TestGCTaskStore_StartNew1506--- PASS: TestGCTaskStore_StartNew (0.00s)1507=== CONT TestCommitRacingPendingCleanupKeepsObjects15082026/10/04 19:46:20 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15092026/10/04 19:46:20 WARN Refused reserved pin name=worker-x86_64-linux15102026/10/04 19:46:20 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15112026/10/04 19:46:20 INFO Received create pin request method=POST path=/api/pins/my-app15122026/10/04 19:46:20 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1513--- PASS: TestCreatePin_ReservedPins (2.15s)1514=== CONT TestPushWaitsForSweepHoldingRow15152026/10/04 19:46:20 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1516--- PASS: TestService_ReadScope_PublicByDefault (2.30s)1517=== CONT TestSweepRechecksPendingAfterLocking15182026/10/04 19:46:21 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161519--- PASS: TestReadProxyNarinfo (2.55s)1520=== CONT TestPresentNotReportedWhileGCDeletesClosure1521--- PASS: TestGetExistingObjectsLocksRows (2.02s)1522=== CONT TestPresentReportsOnlyClosureRoots15232026/10/04 19:46:21 INFO Starting HTTP server address=127.0.0.1:4919815242026/10/04 19:46:21 INFO Starting HTTP server address=/nix/var/nix/builds/nix-96338-3122596536/TestProxyHeadersOnlyTrustedOnSocket3880216054/001/proxy.sock15252026/10/04 19:46:21 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15262026/10/04 19:46:21 INFO Shutdown signal received, draining in-flight requests timeout=10s1527--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.93s)1528=== CONT TestGCSweepDeliversEachKeyOnce1529=== RUN TestPush_RejectsBadRequests/root_not_in_objects1530=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1531=== RUN TestPush_RejectsBadRequests/no_roots1532=== PAUSE TestPush_RejectsBadRequests/no_roots1533=== RUN TestPush_RejectsBadRequests/no_objects1534=== PAUSE TestPush_RejectsBadRequests/no_objects1535=== RUN TestPush_RejectsBadRequests/bad_root1536=== PAUSE TestPush_RejectsBadRequests/bad_root1537=== CONT TestSweepSkipsRowsLockedByPush15382026/10/04 19:46:21 INFO Received push request method=POST path=/api/pushes15392026/10/04 19:46:21 INFO Received complete push request method=POST path=/api/pushes/1/complete15402026/10/04 19:46:21 INFO Received push request method=POST path=/api/pushes15412026/10/04 19:46:22 INFO Aborted multipart uploads count=0 kept=015422026/10/04 19:46:22 WARN Force mode enabled - objects will be deleted immediately without grace period15432026/10/04 19:46:22 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=015442026/10/04 19:46:22 INFO Vacuumed table table=pending_closures15452026/10/04 19:46:22 INFO Vacuumed table table=pending_objects15462026/10/04 19:46:22 INFO Vacuumed table table=multipart_uploads15472026/10/04 19:46:22 INFO Vacuumed table table=closures1548--- PASS: TestGCEndsOnShutdown (2.01s)1549=== CONT TestForceGCDuringPushOffersSweptObject1550=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1551=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1552=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1553=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1554=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15552026/10/04 19:46:22 INFO Vacuumed table table=objects15562026/10/04 19:46:22 INFO Received complete push request method=POST path=/api/pushes/2/complete1557--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.24s)1558=== CONT TestRegisterCompletedObjectNeedsPendingRow15592026/10/04 19:46:22 INFO Aborted multipart uploads count=0 kept=015602026/10/04 19:46:22 WARN Force mode enabled - objects will be deleted immediately without grace period15612026/10/04 19:46: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=015622026/10/04 19:46:22 INFO Vacuumed table table=pending_closures15632026/10/04 19:46:22 INFO Vacuumed table table=pending_objects15642026/10/04 19:46:22 INFO Vacuumed table table=multipart_uploads15652026/10/04 19:46:22 INFO Vacuumed table table=closures15662026/10/04 19:46:22 INFO Vacuumed table table=objects1567--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.28s)1568=== CONT TestFailedS3DeleteKeepsTombstone15692026/10/04 19:46:22 INFO Received uploads request method=POST path=/api/pending_closures15702026/10/04 19:46:23 INFO Aborted multipart uploads count=0 kept=015712026/10/04 19:46:23 WARN Force mode enabled - objects will be deleted immediately without grace period15722026/10/04 19:46:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015732026/10/04 19:46:23 INFO Vacuumed table table=pending_closures15742026/10/04 19:46:23 INFO Vacuumed table table=pending_objects15752026/10/04 19:46:23 INFO Vacuumed table table=multipart_uploads15762026/10/04 19:46:23 INFO Vacuumed table table=closures15772026/10/04 19:46:23 INFO Vacuumed table table=objects1578--- PASS: TestSweepRechecksPendingAfterLocking (2.13s)1579=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1580--- PASS: TestPushWaitsForSweepHoldingRow (2.62s)1581=== CONT TestObjectStatsTrigger1582--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.76s)1583=== CONT TestOrphanedObjectsGC1584--- PASS: TestPresentReportsOnlyClosureRoots (2.02s)1585=== CONT TestPendingCleanupUsesOneCutoff1586--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.26s)1587=== CONT TestMultipartCleanup15882026/10/04 19:46:23 INFO Aborted multipart uploads count=0 kept=015892026/10/04 19:46:23 WARN Force mode enabled - objects will be deleted immediately without grace period15902026/10/04 19:46:23 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=015912026/10/04 19:46:23 INFO Vacuumed table table=pending_closures15922026/10/04 19:46:23 INFO Vacuumed table table=pending_objects15932026/10/04 19:46:23 INFO Vacuumed table table=multipart_uploads15942026/10/04 19:46:23 INFO Vacuumed table table=closures15952026/10/04 19:46:23 INFO Vacuumed table table=objects1596--- PASS: TestGCSweepDeliversEachKeyOnce (2.26s)1597=== CONT TestOrphanedObjectsGCStressTest15982026/10/04 19:46:23 INFO Aborted multipart uploads count=0 kept=015992026/10/04 19:46:23 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/10/04 19:46:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016012026/10/04 19:46:23 INFO Vacuumed table table=pending_closures16022026/10/04 19:46:23 INFO Vacuumed table table=pending_objects16032026/10/04 19:46:23 INFO Vacuumed table table=multipart_uploads16042026/10/04 19:46:23 INFO Vacuumed table table=closures16052026/10/04 19:46:23 INFO Vacuumed table table=objects16062026/10/04 19:46:23 INFO Aborted multipart uploads count=0 kept=016072026/10/04 19:46:23 WARN Force mode enabled - objects will be deleted immediately without grace period16082026/10/04 19:46:23 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=016092026/10/04 19:46:23 INFO Vacuumed table table=pending_closures16102026/10/04 19:46:23 INFO Vacuumed table table=pending_objects16112026/10/04 19:46:23 INFO Vacuumed table table=multipart_uploads16122026/10/04 19:46:23 INFO Vacuumed table table=closures16132026/10/04 19:46:23 INFO Vacuumed table table=objects1614--- PASS: TestSweepSkipsRowsLockedByPush (2.23s)1615=== CONT TestService_AuthMiddleware_MTLSProxyHeader16162026/10/04 19:46:24 INFO Received uploads request method=POST path=/api/pending_closures1617--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.01s)1618=== CONT TestServerTLSConfig/not_a_PEM_file1619=== CONT TestServerTLSConfig/missing_CA_file1620=== CONT TestServerTLSConfig/no_client_CA1621--- PASS: TestServerTLSConfig (0.01s)1622 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1623 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1624 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1625=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16262026/10/04 19:46:24 INFO Received uploads request method=POST path=/1627--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.06s)1628=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16292026/10/04 19:46:24 INFO Received request for more parts method=POST path=/1630=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16312026/10/04 19:46:24 INFO Received complete multipart upload request method=POST path=/1632=== CONT TestResolveDBConnectionString/flag_wins1633=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1634=== CONT TestResolveDBConnectionString/nothing_configured1635=== CONT TestResolveDBConnectionString/missing_file_is_an_error1636=== CONT TestResolveDBConnectionString/file_when_flag_empty1637=== CONT TestPendingClosureWriteTimeout/empty1638=== CONT TestPendingClosureWriteTimeout/670k_objects1639=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1640--- PASS: TestResolveDBConnectionString (0.02s)1641 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1642 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1643 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1644 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1645 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16462026/10/04 19:46:24 INFO Received uploads request method=POST path=/api/pending_closures1647=== CONT TestPendingClosureWriteTimeout/400_objects1648=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1649--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1650 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1651 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1652 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.31s)16532026/10/04 19:46:24 INFO Received uploads request method=POST path=/1654=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16552026/10/04 19:46:24 INFO Received complete multipart upload request method=POST path=/1656=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16572026/10/04 19:46:24 INFO Received request for more parts method=POST path=/1658=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16592026/10/04 19:46:24 INFO Received uploads request method=POST path=/1660--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1661 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1662 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1663 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1664 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1665=== CONT TestIsValidUploadKey/narinfo1666=== CONT TestIsValidUploadKey/realisation_plus_in_output1667=== CONT TestIsValidUploadKey/unknown_type1668=== CONT TestIsValidUploadKey/empty_key1669=== CONT TestIsValidUploadKey/absolute1670=== CONT TestIsValidUploadKey/traversal_nar1671=== CONT TestIsValidUploadKey/traversal1672=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1673=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1674=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1675=== CONT TestIsValidUploadKey/index.html1676=== CONT TestIsValidUploadKey/nix-cache-info1677=== CONT TestIsValidUploadKey/build_log_home-manager_file1678=== CONT TestIsValidUploadKey/realisation1679=== CONT TestIsValidUploadKey/build_log_equals1680=== CONT TestIsValidUploadKey/build_log_question_mark1681=== CONT TestIsValidUploadKey/build_log_plus_in_name1682=== CONT TestIsValidUploadKey/nar_plain1683=== CONT TestIsValidUploadKey/build_log1684=== CONT TestIsValidUploadKey/listing1685=== CONT TestIsValidUploadKey/nar_xz1686=== CONT TestIsValidUploadKey/nar_zst1687--- PASS: TestIsValidUploadKey (0.00s)1688 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1689 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1690 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1691 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1692 --- PASS: TestIsValidUploadKey/absolute (0.00s)1693 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1694 --- PASS: TestIsValidUploadKey/traversal (0.00s)1695 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1696 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1697 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1698 --- PASS: TestIsValidUploadKey/index.html (0.00s)1699 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1700 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1701 --- PASS: TestIsValidUploadKey/realisation (0.00s)1702 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1703 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1704 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1705 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1706 --- PASS: TestIsValidUploadKey/build_log (0.00s)1707 --- PASS: TestIsValidUploadKey/listing (0.00s)1708 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1709 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1710=== CONT TestProxyWriteTimeout/narinfo1711=== CONT TestProxyWriteTimeout/10_GiB_nar1712=== CONT TestProxyWriteTimeout/unknown_size1713=== CONT TestProxyWriteTimeout/1_GiB_nar1714--- PASS: TestProxyWriteTimeout (0.00s)1715 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1716 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1717 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1718 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1719=== CONT TestCacheConfigHandler/full_config,_no_issuer1720=== CONT TestCacheConfigHandler/no_signing_keys1721=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1722=== CONT TestCacheConfigHandler/no_cache_url_configured1723--- PASS: TestCacheConfigHandler (0.00s)1724 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1725 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1726 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1727 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1728=== CONT TestClientErrorHandling/InvalidStorePath17292026/10/04 19:46:24 INFO Aborted multipart uploads count=0 kept=017302026/10/04 19:46:24 WARN Force mode enabled - objects will be deleted immediately without grace period17312026/10/04 19:46:24 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17322026/10/04 19:46:24 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1733--- PASS: TestFailedS3DeleteKeepsTombstone (1.92s)1734=== CONT TestClientErrorHandling/ServerNotAvailable17352026/10/04 19:46:24 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/present17362026/10/04 19:46:24 INFO Received uploads request method=POST path=/api/pending_closures1737--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.63s)1738=== CONT TestClientErrorHandling/InvalidAuthToken17392026/10/04 19:46:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.730346ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1740--- PASS: TestObjectStatsTrigger (1.79s)1741=== CONT TestService_RequireScope_OIDC/builder_may_write1742=== CONT TestService_RequireScope_OIDC/reader_may_read1743=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1744=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17452026/10/04 19:46:24 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1746=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1747=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1748=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1749=== CONT TestService_RequireScope_OIDC/writer_implies_read1750=== CONT TestService_RequireScope_OIDC/reader_may_not_write1751=== CONT TestService_RequireScope_OIDC/static_token_may_write1752=== CONT TestService_RequireScope_OIDC/static_token_may_admin1753=== CONT TestService_RequireScope_OIDC/ops_may_admin1754=== CONT TestService_RequireScope_OIDC/ops_may_not_write1755=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1756=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1757=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17582026/10/04 19:46:24 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]1759=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1760=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17612026/10/04 19:46:24 WARN Authentication failed token_preview=eyJhbGciOi...q8RcBE31gA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1762=== CONT TestIsValidCachePath/narinfo1763=== CONT TestIsValidCachePath/index.html1764=== CONT TestIsValidCachePath/short_hash1765=== CONT TestIsValidCachePath/wrong_extension1766=== CONT TestIsValidCachePath/leading_slash1767=== CONT TestIsValidCachePath/empty1768=== CONT TestIsValidCachePath/random_path1769=== CONT TestIsValidCachePath/invalid_char_u1770=== CONT TestIsValidCachePath/invalid_char_e1771=== CONT TestIsValidCachePath/traversal_in_middle1772=== CONT TestIsValidCachePath/traversal_parent1773=== CONT TestIsValidCachePath/nar_uncompressed1774=== CONT TestIsValidCachePath/nix-cache-info1775=== CONT TestIsValidCachePath/realisation1776=== CONT TestIsValidCachePath/log1777=== CONT TestIsValidCachePath/ls1778=== CONT TestIsValidCachePath/nar_xz1779=== CONT TestIsValidCachePath/nar_bz21780=== CONT TestIsValidCachePath/nar_zst1781=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1782--- PASS: TestIsValidCachePath (0.00s)1783 --- PASS: TestIsValidCachePath/narinfo (0.00s)1784 --- PASS: TestIsValidCachePath/index.html (0.00s)1785 --- PASS: TestIsValidCachePath/short_hash (0.00s)1786 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1787 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1788 --- PASS: TestIsValidCachePath/empty (0.00s)1789 --- PASS: TestIsValidCachePath/random_path (0.00s)1790 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1791 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1792 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1793 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1794 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1795 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1796 --- PASS: TestIsValidCachePath/realisation (0.00s)1797 --- PASS: TestIsValidCachePath/log (0.00s)1798 --- PASS: TestIsValidCachePath/ls (0.00s)1799 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1800 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1801 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1802 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1803=== CONT TestParseSingleRange/none1804=== CONT TestParseSingleRange/open-ended1805=== CONT TestParseSingleRange/start_far_past_EOF1806=== CONT TestParseSingleRange/start_past_EOF1807=== CONT TestParseSingleRange/single_byte1808=== CONT TestParseSingleRange/suffix_exceeds_size1809=== CONT TestParseSingleRange/suffix1810=== CONT TestParseSingleRange/end_clamped_to_size1811=== CONT TestParseSingleRange/malformed_both_empty1812=== CONT TestParseSingleRange/closed1813=== CONT TestParseSingleRange/malformed_end_before_start1814=== CONT TestParseSingleRange/multi-range_ignored1815=== CONT TestParseSingleRange/malformed_no_dash1816=== CONT TestParseSingleRange/unknown_unit1817--- PASS: TestParseSingleRange (0.00s)1818 --- PASS: TestParseSingleRange/none (0.00s)1819 --- PASS: TestParseSingleRange/open-ended (0.00s)1820 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1821 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1822 --- PASS: TestParseSingleRange/single_byte (0.00s)1823 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1824 --- PASS: TestParseSingleRange/suffix (0.00s)1825 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1826 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1827 --- PASS: TestParseSingleRange/closed (0.00s)1828 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1829 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1830 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1831 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1832=== CONT TestPush_RejectsBadRequests/root_not_in_objects18332026/10/04 19:46:24 INFO Received push request method=POST path=/api/pushes1834=== CONT TestPush_RejectsBadRequests/no_objects18352026/10/04 19:46:24 INFO Received push request method=POST path=/api/pushes1836=== CONT TestPush_RejectsBadRequests/bad_root18372026/10/04 19:46:24 INFO Received push request method=POST path=/api/pushes1838=== CONT TestPush_RejectsBadRequests/no_roots18392026/10/04 19:46:24 INFO Received push request method=POST path=/api/pushes1840=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1841--- PASS: TestPush_RejectsBadRequests (1.93s)1842 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1843 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1844 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1845 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1846--- PASS: TestService_AuthMiddleware_OIDC (1.67s)1847 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1848 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1849 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1850 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1851--- PASS: TestService_RequireScope_OIDC (1.80s)1852 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1853 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1854 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1855 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1856 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1857 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1858 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1859 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1860 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1861 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1862 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1863 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1864 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1865 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18662026/10/04 19:46:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.875459ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18672026/10/04 19:46:25 INFO Received uploads request method=POST path=/api/pending_closures18682026/10/04 19:46:25 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/04 19:46:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=828.646841ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18702026/10/04 19:46:25 INFO Received cleanup request method=DELETE path=/api/pending_closures18712026/10/04 19:46:25 INFO Received uploads request method=POST path=/api/pending_closures1872=== NAME TestOrphanedObjectsGC1873 orphaned_objects_gc_test.go:290: GC Test Summary:1874 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1875 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1876 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1877 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1878 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1879--- PASS: TestOrphanedObjectsGC (2.51s)1880=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18812026/10/04 19:46:25 INFO Received cleanup request method=DELETE path=/api/pending_closures18822026/10/04 19:46:25 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket81/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18832026/10/04 19:46:25 INFO Aborted multipart uploads count=0 kept=118842026/10/04 19:46:25 INFO Received cleanup request method=DELETE path=/api/pending_closures18852026/10/04 19:46:25 INFO Aborted multipart uploads count=1 kept=01886--- PASS: TestMultipartCleanup (2.41s)1887--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.27s)18882026/10/04 19:46:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.7244301s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18892026/10/04 19:46:26 INFO Received uploads request method=POST path=/api/pending_closures1890--- PASS: TestPendingClosureWriteTimeout (0.00s)1891 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1892 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1893 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1894 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.00s)18952026/10/04 19:46:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18962026/10/04 19:46:27 INFO Received uploads request method=POST path=/api/pending_closures18972026/10/04 19:46:27 INFO Aborted multipart uploads count=0 kept=018982026/10/04 19:46:27 WARN Force mode enabled - objects will be deleted immediately without grace period18992026/10/04 19:46:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19002026/10/04 19:46:27 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=019012026/10/04 19:46:27 INFO Vacuumed table table=pending_closures19022026/10/04 19:46:27 INFO Vacuumed table table=pending_objects19032026/10/04 19:46:27 INFO Vacuumed table table=multipart_uploads19042026/10/04 19:46:27 INFO Vacuumed table table=closures19052026/10/04 19:46:27 INFO Vacuumed table table=objects19062026/10/04 19:46:28 INFO Received uploads request method=POST path=/api/pending_closures19072026/10/04 19:46:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/10/04 19:46:28 INFO Aborted multipart uploads count=0 kept=019092026/10/04 19:46:28 WARN Force mode enabled - objects will be deleted immediately without grace period19102026/10/04 19:46: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=019112026/10/04 19:46:28 INFO Vacuumed table table=pending_closures19122026/10/04 19:46:28 INFO Vacuumed table table=pending_objects19132026/10/04 19:46:28 INFO Vacuumed table table=multipart_uploads19142026/10/04 19:46:28 INFO Vacuumed table table=closures19152026/10/04 19:46:28 INFO Vacuumed table table=objects1916--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1917 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.65s)1918 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.41s)19192026/10/04 19:46:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.140403ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19202026/10/04 19:46:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.000313ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19212026/10/04 19:46:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=776.341389ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19222026/10/04 19:46:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.477889689s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1923=== NAME TestOrphanedObjectsGCStressTest1924 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1925 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1926 orphaned_objects_gc_test.go:509: Stress test completed successfully:1927 orphaned_objects_gc_test.go:510: - Active objects preserved: 201928 orphaned_objects_gc_test.go:511: - Objects deleted: 2101929 orphaned_objects_gc_test.go:512: - Total GC'd: 2101930--- PASS: TestOrphanedObjectsGCStressTest (6.77s)19312026/10/04 19:46:30 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"19322026/10/04 19:46:30 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-config19332026/10/04 19:46:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.47351ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19342026/10/04 19:46:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.314009ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19352026/10/04 19:46:31 INFO Aborted multipart uploads count=1 kept=019362026/10/04 19:46:31 INFO Received cleanup request method=DELETE path=/api/pending_closures19372026/10/04 19:46:31 INFO Aborted multipart uploads count=1 kept=01938--- PASS: TestPendingCleanupUsesOneCutoff (8.15s)19392026/10/04 19:46:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.157491ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19402026/10/04 19:46:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.652313718s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19412026/10/04 19:46:34 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_closures19422026/10/04 19:46:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.268343ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19432026/10/04 19:46:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.350464ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19442026/10/04 19:46:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.299674ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19452026/10/04 19:46:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.491250833s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1946--- PASS: TestClientErrorHandling (0.00s)1947 --- PASS: TestClientErrorHandling/InvalidStorePath (2.34s)1948 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.79s)1949 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)1950PASS1951{"timestamp":"2026-10-04T19:46:37.198719Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:65380","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(5)"}19522026-10-04 19:46:37.307 UTC [96378] LOG: received smart shutdown request19532026-10-04 19:46:37.308 UTC [96378] LOG: background worker "logical replication launcher" (PID 96388) exited with exit code 119542026-10-04 19:46:37.327 UTC [96383] LOG: shutting down19552026-10-04 19:46:37.327 UTC [96383] LOG: checkpoint starting: shutdown immediate19562026-10-04 19:46:38.587 UTC [96383] LOG: checkpoint complete: wrote 12774 buffers (78.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.717 s, sync=0.508 s, total=1.260 s; sync files=29991, longest=0.001 s, average=0.001 s; distance=421789 kB, estimate=421789 kB; lsn=0/1B3746E8, redo lsn=0/1B3746E819572026-10-04 19:46:38.593 UTC [96378] LOG: database system is shut down1958Running OIDC tests...1959=== RUN TestAudienceForIssuer1960=== PAUSE TestAudienceForIssuer1961=== RUN TestGlobMatch1962=== PAUSE TestGlobMatch1963=== RUN TestValidateToken_ValidToken1964=== PAUSE TestValidateToken_ValidToken1965=== RUN TestValidateToken_WrongAudience1966=== PAUSE TestValidateToken_WrongAudience1967=== RUN TestValidateToken_Expired1968=== PAUSE TestValidateToken_Expired1969=== RUN TestValidateToken_BoundClaimsMismatch1970=== PAUSE TestValidateToken_BoundClaimsMismatch1971=== RUN TestValidateToken_BoundSubjectMismatch1972=== PAUSE TestValidateToken_BoundSubjectMismatch1973=== RUN TestValidateToken_MultipleProviders1974=== PAUSE TestValidateToken_MultipleProviders1975=== RUN TestValidateToken_NoMatchingProvider1976=== PAUSE TestValidateToken_NoMatchingProvider1977=== RUN TestValidateToken_KubernetesServiceAccount1978=== PAUSE TestValidateToken_KubernetesServiceAccount1979=== RUN TestNewValidator_KubernetesRequiresCA1980=== PAUSE TestNewValidator_KubernetesRequiresCA1981=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1982=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1983=== RUN TestPins_ReservedForMatchingRule1984=== PAUSE TestPins_ReservedForMatchingRule1985=== RUN TestPins_TopLevelShorthand1986=== PAUSE TestPins_TopLevelShorthand1987=== RUN TestPins_ConfigValidation1988=== PAUSE TestPins_ConfigValidation1989=== RUN TestScopes_LegacyProviderDefaultsToWrite1990=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1991=== RUN TestScopes_Rules1992=== PAUSE TestScopes_Rules1993=== RUN TestScopes_ConfigValidation1994=== PAUSE TestScopes_ConfigValidation1995=== CONT TestAudienceForIssuer1996--- PASS: TestAudienceForIssuer (0.00s)1997=== CONT TestValidateToken_BoundClaimsMismatch1998=== CONT TestValidateToken_ValidToken1999=== CONT TestValidateToken_NoMatchingProvider2000=== CONT TestValidateToken_MultipleProviders2001=== CONT TestValidateToken_BoundSubjectMismatch2002=== CONT TestPins_ConfigValidation2003=== CONT TestScopes_ConfigValidation2004=== CONT TestScopes_Rules2005--- PASS: TestScopes_ConfigValidation (0.00s)2006=== CONT TestGlobMatch2007=== RUN TestGlobMatch/foo_foo2008=== PAUSE TestGlobMatch/foo_foo2009=== RUN TestGlobMatch/foo_bar2010=== PAUSE TestGlobMatch/foo_bar2011=== RUN TestGlobMatch/*_2012=== PAUSE TestGlobMatch/*_2013=== RUN TestGlobMatch/*_anything2014=== PAUSE TestGlobMatch/*_anything2015=== RUN TestGlobMatch/foo*_foo2016=== PAUSE TestGlobMatch/foo*_foo2017=== RUN TestGlobMatch/foo*_foobar2018=== PAUSE TestGlobMatch/foo*_foobar2019=== RUN TestGlobMatch/foo*_bar2020=== PAUSE TestGlobMatch/foo*_bar2021=== RUN TestGlobMatch/*bar_bar2022=== PAUSE TestGlobMatch/*bar_bar2023=== RUN TestGlobMatch/*bar_foobar2024=== PAUSE TestGlobMatch/*bar_foobar2025=== RUN TestGlobMatch/*bar_foo2026=== PAUSE TestGlobMatch/*bar_foo2027=== RUN TestGlobMatch/foo*bar_foobar2028=== PAUSE TestGlobMatch/foo*bar_foobar2029=== RUN TestGlobMatch/foo*bar_foo123bar2030=== PAUSE TestGlobMatch/foo*bar_foo123bar2031=== RUN TestGlobMatch/foo*bar_foobarbaz2032=== PAUSE TestGlobMatch/foo*bar_foobarbaz2033=== RUN TestGlobMatch/*/*_foo/bar2034=== PAUSE TestGlobMatch/*/*_foo/bar2035=== RUN TestGlobMatch/*/*_foo2036=== PAUSE TestGlobMatch/*/*_foo2037=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2038=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2039=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02040=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02041=== RUN TestGlobMatch/refs/*/main_refs/heads/main2042=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2043=== RUN TestGlobMatch/fo?_foo2044=== PAUSE TestGlobMatch/fo?_foo2045=== RUN TestGlobMatch/fo?_fo2046=== PAUSE TestGlobMatch/fo?_fo2047=== RUN TestGlobMatch/fo?_fooo2048=== PAUSE TestGlobMatch/fo?_fooo2049=== RUN TestGlobMatch/?oo_foo2050=== PAUSE TestGlobMatch/?oo_foo2051=== RUN TestGlobMatch/?oo_boo2052=== PAUSE TestGlobMatch/?oo_boo2053=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2054=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2055=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2056=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2057--- PASS: TestPins_ConfigValidation (0.00s)2058=== CONT TestValidateToken_KubernetesServiceAccount2059=== CONT TestValidateToken_Expired2060=== CONT TestScopes_LegacyProviderDefaultsToWrite2061=== CONT TestPins_ReservedForMatchingRule20622026/10/04 19:46:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49321/oidc20632026/10/04 19:46:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49323/oidc2064--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2065=== CONT TestPins_TopLevelShorthand2066--- PASS: TestValidateToken_Expired (0.04s)2067=== CONT TestValidateToken_KubernetesIssuerFromOwnToken20682026/10/04 19:46:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49326/oidc2069--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2070=== CONT TestNewValidator_KubernetesRequiresCA20712026/10/04 19:46:39 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49325/oidc2072--- PASS: TestValidateToken_NoMatchingProvider (0.07s)2073=== CONT TestValidateToken_WrongAudience20742026/10/04 19:46:39 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:493282075--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2076=== CONT TestGlobMatch/foo_foo2077=== CONT TestGlobMatch/*/*_foo/bar2078=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2079=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2080=== CONT TestGlobMatch/fo?_foo2081=== CONT TestGlobMatch/refs/*/main_refs/heads/main2082=== CONT TestGlobMatch/?oo_boo2083=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02084=== CONT TestGlobMatch/?oo_foo2085=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2086=== CONT TestGlobMatch/fo?_fooo2087=== CONT TestGlobMatch/*/*_foo2088=== CONT TestGlobMatch/fo?_fo2089=== CONT TestGlobMatch/*bar_bar2090=== CONT TestGlobMatch/foo*bar_foobarbaz2091=== CONT TestGlobMatch/foo*bar_foo123bar2092=== CONT TestGlobMatch/foo*bar_foobar2093=== CONT TestGlobMatch/*bar_foo2094=== CONT TestGlobMatch/*bar_foobar2095=== CONT TestGlobMatch/foo*_foo2096=== CONT TestGlobMatch/foo*_bar2097=== CONT TestGlobMatch/foo*_foobar2098=== CONT TestGlobMatch/*_anything2099=== CONT TestGlobMatch/*_2100=== CONT TestGlobMatch/foo_bar2101--- PASS: TestGlobMatch (0.01s)2102 --- PASS: TestGlobMatch/foo_foo (0.00s)2103 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2104 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2105 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2106 --- PASS: TestGlobMatch/fo?_foo (0.00s)2107 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2108 --- PASS: TestGlobMatch/?oo_boo (0.00s)2109 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2110 --- PASS: TestGlobMatch/?oo_foo (0.00s)2111 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2112 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2113 --- PASS: TestGlobMatch/*/*_foo (0.00s)2114 --- PASS: TestGlobMatch/fo?_fo (0.00s)2115 --- PASS: TestGlobMatch/*bar_bar (0.00s)2116 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2117 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2118 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2119 --- PASS: TestGlobMatc2026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49332/oidc2120h/*bar_foo (0.00s)2121 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2122 --- PASS: TestGlobMatch/foo*_foo (0.00s)2123 --- PASS: TestGlobMatch/foo*_bar (0.00s)2124 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2125 --- PASS: TestGlobMatch/*_anything (0.00s)2126 --- PASS: TestGlobMatch/*_ (0.00s)2127 --- PASS: TestGlobMatch/foo_bar (0.00s)21282026/10/04 19:46:40 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232129--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2130--- PASS: TestScopes_Rules (0.08s)21312026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49338/oidc2132--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)21332026/10/04 19:46:40 http: TLS handshake error from 127.0.0.1:49341: remote error: tls: bad certificate2134--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)21352026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49342/oidc2136--- PASS: TestValidateToken_ValidToken (0.12s)21372026/10/04 19:46:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49334/oidc21382026/10/04 19:46:40 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49344/oidc21392026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49347/oidc2140--- PASS: TestValidateToken_MultipleProviders (0.12s)2141--- PASS: TestPins_ReservedForMatchingRule (0.12s)21422026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49349/oidc2143--- PASS: TestValidateToken_WrongAudience (0.05s)21442026/10/04 19:46:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49351/oidc2145--- PASS: TestPins_TopLevelShorthand (0.15s)2146PASS2147Running hook tests...2148=== RUN TestSendPathsEmpty2149=== PAUSE TestSendPathsEmpty2150=== RUN TestQueueEnqueueAndFetch2151=== PAUSE TestQueueEnqueueAndFetch2152=== RUN TestQueueDeduplication2153=== PAUSE TestQueueDeduplication2154=== RUN TestQueueRemove2155=== PAUSE TestQueueRemove2156=== RUN TestQueueFetchBatchLimit2157=== PAUSE TestQueueFetchBatchLimit2158=== RUN TestQueueRetryMovesToBack2159=== PAUSE TestQueueRetryMovesToBack2160=== RUN TestQueueFetchRemoveLifecycle2161=== PAUSE TestQueueFetchRemoveLifecycle2162=== RUN TestQueueConcurrentWriters2163=== PAUSE TestQueueConcurrentWriters2164=== RUN TestQueueRemoveLargeClosure2165=== PAUSE TestQueueRemoveLargeClosure2166=== RUN TestServerClientIntegration2167=== PAUSE TestServerClientIntegration2168=== RUN TestServerQueueError2169=== PAUSE TestServerQueueError2170=== RUN TestGetListenerSocketActivation2171 server_test.go:210: === RUN TestGetListenerSocketActivation2172 --- PASS: TestGetListenerSocketActivation (0.00s)2173 PASS2174 2175--- PASS: TestGetListenerSocketActivation (0.01s)2176=== RUN TestDrainIsolatesPoisonPath2177=== PAUSE TestDrainIsolatesPoisonPath2178=== RUN TestRunNotBlockedByPoisonHead2179=== PAUSE TestRunNotBlockedByPoisonHead2180=== RUN TestDrainGivesUpWhenServerDown2181=== PAUSE TestDrainGivesUpWhenServerDown2182=== RUN TestFailedPathPrunedByLaterClosure2183=== PAUSE TestFailedPathPrunedByLaterClosure2184=== RUN TestWorkerUploadsAndRemoves2185=== PAUSE TestWorkerUploadsAndRemoves2186=== RUN TestWorkerSkipsGCdPaths2187=== PAUSE TestWorkerSkipsGCdPaths2188=== RUN TestWorkerPrunesClosureDeps2189=== PAUSE TestWorkerPrunesClosureDeps2190=== RUN TestDrainTimeout2191=== PAUSE TestDrainTimeout2192=== CONT TestSendPathsEmpty2193=== CONT TestServerQueueError2194=== CONT TestQueueRetryMovesToBack2195--- PASS: TestSendPathsEmpty (0.00s)2196=== CONT TestQueueFetchBatchLimit2197=== CONT TestQueueRemove2198=== CONT TestQueueDeduplication2199=== CONT TestQueueEnqueueAndFetch2200=== CONT TestQueueRemoveLargeClosure2201=== CONT TestServerClientIntegration2202=== CONT TestWorkerUploadsAndRemoves2203=== CONT TestDrainTimeout22042026/10/04 19:46:40 ERROR Failed to queue paths error="permission denied" count=12205--- PASS: TestServerQueueError (0.00s)2206=== CONT TestWorkerPrunesClosureDeps2207--- PASS: TestServerClientIntegration (0.00s)2208=== CONT TestWorkerSkipsGCdPaths2209--- PASS: TestQueueEnqueueAndFetch (0.01s)2210=== CONT TestQueueConcurrentWriters22112026/10/04 19:46:40 INFO Upload queue status pending=222122026/10/04 19:46:40 INFO Uploading batch count=222132026/10/04 19:46:40 INFO Uploading batch count=122142026/10/04 19:46:40 INFO Upload queue status pending=222152026/10/04 19:46:40 INFO Uploading batch count=222162026/10/04 19:46:40 INFO Upload queue status pending=222172026/10/04 19:46:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-96338-3122596536/TestWorkerSkipsGCdPaths3485056648/002/nonexistent2218--- PASS: TestQueueRetryMovesToBack (0.01s)2219=== CONT TestDrainGivesUpWhenServerDown2220--- PASS: TestQueueFetchBatchLimit (0.01s)2221=== CONT TestFailedPathPrunedByLaterClosure2222--- PASS: TestQueueRemove (0.01s)2223=== CONT TestRunNotBlockedByPoisonHead22242026/10/04 19:46:40 INFO Uploading batch count=12225--- PASS: TestQueueDeduplication (0.01s)2226=== CONT TestQueueFetchRemoveLifecycle22272026/10/04 19:46:40 INFO Upload queue status pending=322282026/10/04 19:46:40 INFO Uploading batch count=122292026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=122302026/10/04 19:46:40 INFO Uploading batch count=122312026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=12232--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2233=== CONT TestDrainIsolatesPoisonPath22342026/10/04 19:46:40 INFO Uploading batch count=122352026/10/04 19:46:40 INFO Uploading batch count=222362026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=222372026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/a22382026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/b22392026/10/04 19:46:40 INFO Uploading batch count=222402026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=222412026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/c22422026/10/04 19:46:40 INFO Uploading batch count=122432026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/d22442026/10/04 19:46:40 INFO Uploading batch count=222452026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=222462026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/e22472026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainGivesUpWhenServerDown3063294664/002/f22482026/10/04 19:46:40 ERROR Drain finished with paths left in queue remaining=102249--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22502026/10/04 19:46:40 INFO Uploading batch count=422512026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=422522026/10/04 19:46:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-96338-3122596536/TestDrainIsolatesPoisonPath3430235912/002/bbb22532026/10/04 19:46:40 INFO Uploading batch count=122542026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=122552026/10/04 19:46:40 INFO Uploading batch count=122562026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=12257--- PASS: TestDrainGivesUpWhenServerDown (0.01s)22582026/10/04 19:46:40 INFO Uploading batch count=122592026/10/04 19:46:40 ERROR Upload failed error="upload failed" count=122602026/10/04 19:46:40 ERROR Drain finished with paths left in queue remaining=12261--- PASS: TestDrainIsolatesPoisonPath (0.00s)2262--- PASS: TestWorkerPrunesClosureDeps (0.03s)2263--- PASS: TestWorkerSkipsGCdPaths (0.03s)2264--- PASS: TestWorkerUploadsAndRemoves (0.03s)2265--- PASS: TestQueueRemoveLargeClosure (0.06s)2266--- PASS: TestQueueConcurrentWriters (0.15s)22672026/10/04 19:46:40 ERROR Upload failed error="context deadline exceeded" count=222682026/10/04 19:46:40 ERROR Drain finished with paths left in queue remaining=42269--- PASS: TestDrainTimeout (0.21s)22702026/10/04 19:46:41 INFO Uploading batch count=122712026/10/04 19:46:41 INFO Uploading batch count=122722026/10/04 19:46:41 INFO Uploading batch count=122732026/10/04 19:46:41 ERROR Upload failed error="upload failed" count=122742026/10/04 19:46:41 INFO Uploading batch count=122752026/10/04 19:46:41 ERROR Upload failed error="upload failed" count=122762026/10/04 19:46:41 INFO Uploading batch count=122772026/10/04 19:46:41 ERROR Upload failed error="upload failed" count=122782026/10/04 19:46:41 INFO Uploading batch count=122792026/10/04 19:46:41 ERROR Upload failed error="upload failed" count=122802026/10/04 19:46:41 ERROR Drain finished with paths left in queue remaining=12281--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2282PASS