niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #347
· 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.05s)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 TestScriptTokenNoExpiryRerunsEveryCall98=== CONT TestFileTokenEmpty99=== CONT TestFileTokenMissing100=== CONT TestClientSignaturesByStorePath101=== CONT TestStreamPushReportsSignatures102=== CONT TestFileTokenReadsAndCaches103=== CONT TestStaticToken104=== CONT TestStreamPushBatchesUnderLoad105=== CONT TestStreamPushRequestLine106=== CONT TestSetClientTLSDoesNotMutateDefaultTransport107--- PASS: TestShellSplit (0.00s)108--- PASS: TestFileTokenEmpty (0.00s)109--- PASS: TestClientSignaturesByStorePath (0.00s)110--- PASS: TestStaticToken (0.00s)111=== CONT TestSetClientTLS112--- PASS: TestFileTokenReadsAndCaches (0.00s)113=== CONT TestStreamPushGivesUpOnDeadServer114--- PASS: TestFileTokenMissing (0.00s)115=== CONT TestStreamPushIsolatesFailures1162026/10/01 13:03:25 ERROR Upload failed error="bad path" count=3117--- PASS: TestStreamPushIsolatesFailures (0.00s)118=== CONT TestEncodeNixBase32WithRealHash119--- PASS: TestEncodeNixBase32WithRealHash (0.00s)120=== CONT TestDoWithRetry_BodyReplayedViaGetBody1212026/10/01 13:03:25 ERROR Upload failed error=boom count=11222026/10/01 13:03:25 ERROR Upload failed error="connection refused" count=201232026/10/01 13:03:25 ERROR Server seems unavailable, giving up on batch untried=171242026/10/01 13:03:25 ERROR Upload failed error=boom count=1125--- PASS: TestStreamPushReportsSignatures (0.00s)126=== CONT TestScriptTokenCachesUntilRefresh127--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)128=== CONT TestScriptTokenEmptyCommand129--- PASS: TestScriptTokenEmptyCommand (0.00s)130=== CONT TestScriptTokenScriptFails131=== RUN TestSetClientTLSErrors/missing_cert_file132=== PAUSE TestSetClientTLSErrors/missing_cert_file133=== RUN TestSetClientTLSErrors/missing_key_file134=== PAUSE TestSetClientTLSErrors/missing_key_file135=== RUN TestSetClientTLSErrors/missing_ca_file136=== PAUSE TestSetClientTLSErrors/missing_ca_file137=== RUN TestSetClientTLSErrors/invalid_ca_file1382026/10/01 13:03:25 WARN Rate limiter enabled after throttle name=server-test rate=5139=== PAUSE TestSetClientTLSErrors/invalid_ca_file140=== CONT TestScriptTokenBadJSON1412026/10/01 13:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50346142--- PASS: TestDoServerRequestAttachesToken (0.00s)143=== CONT TestScriptTokenEmptyToken1442026/10/01 13:03:25 WARN Rate limiter backed off name=server-test rate=51452026/10/01 13:03:25 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50346146--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)147=== CONT TestUploadMultipart_SupersededByPeer148=== RUN TestUploadMultipart_SupersededByPeer/exists149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150=== RUN TestUploadMultipart_SupersededByPeer/missing151--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)152=== PAUSE TestUploadMultipart_SupersededByPeer/missing153=== CONT TestEncodeNixBase32154=== RUN TestEncodeNixBase32/test_string_hash155=== PAUSE TestEncodeNixBase32/test_string_hash156=== CONT TestDumpPathWriterError157=== RUN TestEncodeNixBase32/empty_input158=== PAUSE TestEncodeNixBase32/empty_input159=== CONT TestDumpPathSingleFile160--- PASS: TestScriptTokenScriptFails (0.00s)161=== CONT TestDumpPathMatchesNix162=== RUN TestSetClientTLS/rejects_connection_without_client_cert163=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert164=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA165=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA166=== RUN TestSetClientTLS/preserves_debug_logging_transport167=== PAUSE TestSetClientTLS/preserves_debug_logging_transport168=== CONT TestFilterOversizedClosures169=== RUN TestFilterOversizedClosures/no_limit_keeps_everything170=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything171=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped172=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped173=== RUN TestFilterOversizedClosures/all_closures_skipped174=== PAUSE TestFilterOversizedClosures/all_closures_skipped175=== CONT TestPartSizeForNAR176=== RUN TestPartSizeForNAR/zero_stays_at_minimum177=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum178=== RUN TestPartSizeForNAR/small_stays_at_minimum179=== PAUSE TestPartSizeForNAR/small_stays_at_minimum180=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum181=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum182=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts183=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts184=== RUN TestPartSizeForNAR/1_TiB185=== PAUSE TestPartSizeForNAR/1_TiB186=== RUN TestPartSizeForNAR/5_TiB_S3_max_object187=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object188=== RUN TestPartSizeForNAR/capped_at_5_GiB189=== PAUSE TestPartSizeForNAR/capped_at_5_GiB190=== CONT TestUploadMultipart_PartsInParallel191--- PASS: TestScriptTokenBadJSON (0.01s)192=== CONT TestStreamPushReportsEveryPath193--- PASS: TestStreamPushReportsEveryPath (0.00s)194=== CONT TestParsePathInfoJSONMultiplePaths195=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths196=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2002026/10/01 13:03:25 WARN Rate limiter enabled after throttle name=server-test rate=5201--- PASS: TestScriptTokenEmptyToken (0.01s)202=== CONT TestRateLimiterFeedback203=== RUN TestRateLimiterFeedback/429_enables_limiter204=== PAUSE TestRateLimiterFeedback/429_enables_limiter205=== RUN TestRateLimiterFeedback/503_enables_limiter206=== PAUSE TestRateLimiterFeedback/503_enables_limiter207=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter208=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter209=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter210=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter211=== CONT TestPathInfoCACompatibility212=== RUN TestPathInfoCACompatibility/null_ca_field213=== PAUSE TestPathInfoCACompatibility/null_ca_field214=== RUN TestPathInfoCACompatibility/old_string_format_-_text215=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text216=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive217=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive218=== RUN TestPathInfoCACompatibility/new_structured_format_-_text219=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text220=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method221=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method222=== CONT TestPathInfoHashCompatibility223=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)224=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)225=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon226=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon227=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI228=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512230=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512231=== CONT TestParsePathInfoJSON232=== RUN TestParsePathInfoJSON/Nix_format233=== PAUSE TestParsePathInfoJSON/Nix_format234=== RUN TestParsePathInfoJSON/Lix_format235=== PAUSE TestParsePathInfoJSON/Lix_format236=== RUN TestParsePathInfoJSON/empty_input237=== PAUSE TestParsePathInfoJSON/empty_input238=== RUN TestParsePathInfoJSON/whitespace_only239=== PAUSE TestParsePathInfoJSON/whitespace_only240=== RUN TestParsePathInfoJSON/invalid_JSON241=== PAUSE TestParsePathInfoJSON/invalid_JSON242=== CONT TestGetStorePathHash243=== RUN TestGetStorePathHash/valid_store_path244=== PAUSE TestGetStorePathHash/valid_store_path245=== RUN TestGetStorePathHash/basename_without_hyphen_should_error246=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error247=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error248=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error249=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error250=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error251=== CONT TestCaseHackSuffix252--- PASS: TestStreamPushRequestLine (0.02s)253=== CONT TestConvertHashToNix32254=== RUN TestConvertHashToNix32/SRI_format_to_Nix32255=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32256=== RUN TestConvertHashToNix32/already_Nix32_format257=== PAUSE TestConvertHashToNix32/already_Nix32_format258=== RUN TestConvertHashToNix32/invalid_format259=== PAUSE TestConvertHashToNix32/invalid_format260=== CONT TestShellSplitErrors261--- PASS: TestShellSplitErrors (0.00s)262=== CONT TestRegisterUploadedObjectReusesConnections263--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)264=== CONT TestResolveStorePath265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268=== CONT TestSetClientTLSErrors/invalid_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270--- PASS: TestResolveStorePath (0.00s)271=== CONT TestUploadMultipart_SupersededByPeer/missing272--- PASS: TestSetClientTLSErrors (0.00s)273 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)274 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)275 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)276 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)277=== CONT TestUploadMultipart_SupersededByPeer/exists278=== CONT TestEncodeNixBase32/test_string_hash279--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)280 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)281 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)282=== CONT TestEncodeNixBase32/empty_input283--- PASS: TestEncodeNixBase32 (0.00s)284 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)285 --- PASS: TestEncodeNixBase32/empty_input (0.00s)286=== CONT TestFilterOversizedClosures/no_limit_keeps_everything287=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA288=== CONT TestSetClientTLS/rejects_connection_without_client_cert289=== CONT TestSetClientTLS/preserves_debug_logging_transport290--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)291=== CONT TestFilterOversizedClosures/all_closures_skipped2922026/10/01 13:03:25 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=50293=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2942026/10/01 13:03:25 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=2000295--- PASS: TestFilterOversizedClosures (0.00s)296 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)297 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)298 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)299=== CONT TestPartSizeForNAR/zero_stays_at_minimum300=== CONT TestPartSizeForNAR/1_TiB301=== CONT TestPartSizeForNAR/capped_at_5_GiB302=== CONT TestPartSizeForNAR/5_TiB_S3_max_object303=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum304=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts305=== CONT TestPartSizeForNAR/small_stays_at_minimum306--- PASS: TestPartSizeForNAR (0.00s)307 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)308 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)309 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)310 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)311 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)312 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)313 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)314=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths315=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths316--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)319=== CONT TestRateLimiterFeedback/429_enables_limiter320=== CONT TestPathInfoCACompatibility/null_ca_field321=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3222026/10/01 13:03:25 WARN Rate limiter enabled after throttle name=server-test rate=53232026/10/01 13:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:504283242026/10/01 13:03:25 WARN Rate limiter backed off name=server-test rate=5325=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter326=== CONT TestRateLimiterFeedback/503_enables_limiter327=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3292026/10/01 13:03:25 WARN Rate limiter enabled after throttle name=server-test rate=53302026/10/01 13:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:50434331=== CONT TestPathInfoCACompatibility/old_string_format_-_text332=== CONT TestPathInfoCACompatibility/new_structured_format_-_text333--- PASS: TestPathInfoCACompatibility (0.00s)334 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)338 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)3392026/10/01 13:03:25 WARN Rate limiter backed off name=server-test rate=5340=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)341=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI342--- PASS: TestRateLimiterFeedback (0.00s)343 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)344 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)345 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)346 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)347=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon348=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512349--- PASS: TestPathInfoHashCompatibility (0.00s)350 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)351 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)352 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)354=== CONT TestParsePathInfoJSON/Nix_format355=== CONT TestParsePathInfoJSON/whitespace_only356=== CONT TestParsePathInfoJSON/invalid_JSON357=== CONT TestParsePathInfoJSON/empty_input358=== CONT TestParsePathInfoJSON/Lix_format359=== CONT TestGetStorePathHash/valid_store_path360=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error361=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error362=== CONT TestGetStorePathHash/basename_without_hyphen_should_error363--- PASS: TestParsePathInfoJSON (0.00s)364 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)365 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)366 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)367 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)368 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)369--- PASS: TestGetStorePathHash (0.00s)370 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)371 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)372 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)373 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)374=== CONT TestConvertHashToNix32/invalid_format375=== CONT TestConvertHashToNix32/already_Nix32_format376=== CONT TestConvertHashToNix32/SRI_format_to_Nix32377--- PASS: TestConvertHashToNix32 (0.00s)378 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)379 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)380 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)381--- PASS: TestDumpPathWriterError (0.04s)3822026/10/01 13:03:25 http: TLS handshake error from 127.0.0.1:50425: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.01s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-17449-2882215670/postgres4151058349/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-17449-2882215670/postgres4151058349/data -l logfile start421422/nix/var/nix/builds/nix-17449-2882215670/postgres4151058349:5432 - no response4232026-10-01 13:03:26.861 UTC [17486] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 13:03:26.861 UTC [17486] LOG: listening on Unix socket "/nix/var/nix/builds/nix-17449-2882215670/postgres4151058349/.s.PGSQL.5432"4252026-10-01 13:03:26.863 UTC [17493] LOG: database system was shut down at 2026-10-01 13:03:26 UTC4262026-10-01 13:03:26.864 UTC [17486] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-17449-2882215670/postgres4151058349:5432 - accepting connections428{"timestamp":"2026-10-01T13:03:27.07965Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"617792fa-ddde-40b7-99fc-2304f94ab50b","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(4)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestConnectWaitsForAPeerMigration470=== PAUSE TestConnectWaitsForAPeerMigration471=== RUN TestLeadElectsOneAndHandsOver472=== PAUSE TestLeadElectsOneAndHandsOver473=== RUN TestLeadIncumbentWinsAfterRestart4742026/10/01 13:03:27 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 13:03:28 INFO lead: released remote=192.0.2.1:12344762026/10/01 13:03:28 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 13:03:29 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (2.35s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestLeadEndsWhenItsConnectionHangs4822026/10/01 13:03:29 INFO lead: acquired remote=192.0.2.1:12344832026-10-01 13:03:30.890 UTC [17528] FATAL: terminating connection due to administrator command4842026/10/01 13:03:31 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 13:03:32 WARN lead: lock connection lost error="timeout: context deadline exceeded"4862026/10/01 13:03:32 INFO lead: released remote=192.0.2.1:12344872026/10/01 13:03:32 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)489=== RUN TestGCAdvisoryLockBlocksConcurrentRun490=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun491=== RUN TestGCBugBareHashReferences492=== PAUSE TestGCBugBareHashReferences493=== RUN TestGCMetrics494=== PAUSE TestGCMetrics495=== RUN TestPushDedupSurvivesConcurrentGC496=== PAUSE TestPushDedupSurvivesConcurrentGC497=== RUN TestDeduplicatedObjectsRecordedAsPending498=== PAUSE TestDeduplicatedObjectsRecordedAsPending499=== RUN TestGCSweepSkipsPendingObjects500=== PAUSE TestGCSweepSkipsPendingObjects501=== RUN TestTombstonedObjectOfferedWithoutWaiting502=== PAUSE TestTombstonedObjectOfferedWithoutWaiting503=== RUN TestGCSweepDeliversEachKeyOnce504=== PAUSE TestGCSweepDeliversEachKeyOnce505=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection506=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection507=== RUN TestForceGCDuringPushOffersSweptObject508=== PAUSE TestForceGCDuringPushOffersSweptObject509=== RUN TestFailedS3DeleteKeepsTombstone510=== PAUSE TestFailedS3DeleteKeepsTombstone511=== RUN TestSweepSkipsRowsLockedByPush512=== PAUSE TestSweepSkipsRowsLockedByPush513=== RUN TestRegisterCompletedObjectNeedsPendingRow514=== PAUSE TestRegisterCompletedObjectNeedsPendingRow515=== RUN TestGetExistingObjectsLocksRows516=== PAUSE TestGetExistingObjectsLocksRows517=== RUN TestSweepRechecksPendingAfterLocking518=== PAUSE TestSweepRechecksPendingAfterLocking519=== RUN TestPushWaitsForSweepHoldingRow520=== PAUSE TestPushWaitsForSweepHoldingRow521=== RUN TestCommitRacingPendingCleanupKeepsObjects522=== PAUSE TestCommitRacingPendingCleanupKeepsObjects523=== RUN TestGCEndsOnShutdown524=== PAUSE TestGCEndsOnShutdown525=== RUN TestGCTaskStore_StartNew526=== PAUSE TestGCTaskStore_StartNew527=== RUN TestGCTaskStore_DeduplicateSameParams528=== PAUSE TestGCTaskStore_DeduplicateSameParams529=== RUN TestGCTaskStore_ConflictDifferentParams530=== PAUSE TestGCTaskStore_ConflictDifferentParams531=== RUN TestGCTaskStore_GetEmpty532=== PAUSE TestGCTaskStore_GetEmpty533=== RUN TestGCTaskStore_GetReturnsLatest534=== PAUSE TestGCTaskStore_GetReturnsLatest535=== RUN TestGCTaskStore_CompletedAllowsNewTask536=== PAUSE TestGCTaskStore_CompletedAllowsNewTask537=== RUN TestGCTaskStore_PhaseUpdates538=== PAUSE TestGCTaskStore_PhaseUpdates539=== RUN TestGCTaskStore_Fail540=== PAUSE TestGCTaskStore_Fail541=== RUN TestGracefulShutdownDrainsInflight542=== PAUSE TestGracefulShutdownDrainsInflight543=== RUN TestService_healthCheckHandler544=== PAUSE TestService_healthCheckHandler545=== RUN TestService_readinessHandler546=== PAUSE TestService_readinessHandler547=== RUN TestGenerateLandingPage548=== PAUSE TestGenerateLandingPage549=== RUN TestCacheConfigHandlerMaxNarSize550=== PAUSE TestCacheConfigHandlerMaxNarSize551=== RUN TestCreatePendingClosureRejectsOversizedNAR552=== PAUSE TestCreatePendingClosureRejectsOversizedNAR553=== RUN TestNARDeduplicationMetadataUploadBug554=== PAUSE TestNARDeduplicationMetadataUploadBug555=== RUN TestMetricsInventory556=== PAUSE TestMetricsInventory557=== RUN TestService_NativeMTLS558=== PAUSE TestService_NativeMTLS559=== RUN TestServerTLSConfig560=== PAUSE TestServerTLSConfig561=== RUN TestMultipartCleanup562=== PAUSE TestMultipartCleanup563=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded564=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded565=== RUN TestPendingCleanupUsesOneCutoff566=== PAUSE TestPendingCleanupUsesOneCutoff567=== RUN TestObjectStatsTrigger568=== PAUSE TestObjectStatsTrigger569=== RUN TestOrphanedObjectsGC570=== PAUSE TestOrphanedObjectsGC571=== RUN TestOrphanedObjectsGCStressTest572=== PAUSE TestOrphanedObjectsGCStressTest573=== RUN TestCreatePin_ReservedPins574=== PAUSE TestCreatePin_ReservedPins575=== RUN TestPresentReportsOnlyClosureRoots576=== PAUSE TestPresentReportsOnlyClosureRoots577=== RUN TestPresentNotReportedWhileGCDeletesClosure578=== PAUSE TestPresentNotReportedWhileGCDeletesClosure579=== RUN TestParseSingleRange580=== PAUSE TestParseSingleRange581=== RUN TestProxyHeadersOnlyTrustedOnSocket582=== PAUSE TestProxyHeadersOnlyTrustedOnSocket583=== RUN TestIsValidCachePath584=== PAUSE TestIsValidCachePath585=== RUN TestReadProxyNarinfo586=== PAUSE TestReadProxyNarinfo587=== RUN TestReadProxyNarinfoAlreadyDecompressed588=== PAUSE TestReadProxyNarinfoAlreadyDecompressed589=== RUN TestReadProxyNarStreaming590=== PAUSE TestReadProxyNarStreaming591=== RUN TestReadProxy404592=== PAUSE TestReadProxy404593=== RUN TestReadProxyInvalidPath594=== PAUSE TestReadProxyInvalidPath595=== RUN TestReadProxyHead596=== PAUSE TestReadProxyHead597=== RUN TestReadProxyOutlastsServerWriteTimeout598=== PAUSE TestReadProxyOutlastsServerWriteTimeout599=== RUN TestReadProxyConditionalGet600=== PAUSE TestReadProxyConditionalGet601=== RUN TestReadProxyRootRedirectsToIndexHTML602=== PAUSE TestReadProxyRootRedirectsToIndexHTML603=== RUN TestReadProxyDisabled604=== PAUSE TestReadProxyDisabled605=== RUN TestReadRedirectNar606=== PAUSE TestReadRedirectNar607=== RUN TestReadRedirectKeepsNarinfoProxied608=== PAUSE TestReadRedirectKeepsNarinfoProxied609=== RUN TestReadProxyRangeRequest610=== PAUSE TestReadProxyRangeRequest611=== RUN TestReadRedirectUsesPublicS3URL612=== PAUSE TestReadRedirectUsesPublicS3URL613=== RUN TestPush_OverlappingRootsStoreOneRowPerKey614=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey615=== RUN TestPush_CompleteCommitsEveryRoot616=== PAUSE TestPush_CompleteCommitsEveryRoot617=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit618=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit619=== RUN TestPush_RejectsBadRequests620=== PAUSE TestPush_RejectsBadRequests621=== RUN TestPush_SignsNarinfosOfItsPendingObjects622=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects623=== RUN TestRedundantMultipartUpload624=== PAUSE TestRedundantMultipartUpload625=== RUN TestCompleteMultipartUpload_ErrorButObjectExists626=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists627=== RUN TestCompletedNarNotReofferedAcrossClosures628=== PAUSE TestCompletedNarNotReofferedAcrossClosures629=== RUN TestPresignedUploadRegisteredBeforeCommit630=== PAUSE TestPresignedUploadRegisteredBeforeCommit631=== RUN TestService_Rustfstest632=== PAUSE TestService_Rustfstest633=== RUN TestParseSize634=== PAUSE TestParseSize635=== RUN TestSkippedUploadsHandler636=== PAUSE TestSkippedUploadsHandler637=== RUN TestSystemdListenerNotActivated638--- PASS: TestSystemdListenerNotActivated (0.00s)639=== RUN TestWatchdogBeatsWhenHealthy640--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)641=== RUN TestWatchdogSkipsWhenUnhealthy6422026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 13:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"651--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)652=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle653=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== RUN TestProxyWriteTimeout655=== PAUSE TestProxyWriteTimeout656=== RUN TestPendingClosureWriteTimeout657=== PAUSE TestPendingClosureWriteTimeout658=== RUN TestIsValidUploadKey659=== PAUSE TestIsValidUploadKey660=== RUN TestUploadHandlersRejectInvalidKeys661=== PAUSE TestUploadHandlersRejectInvalidKeys662=== RUN TestUploadHandlersRejectOversizedBody663=== PAUSE TestUploadHandlersRejectOversizedBody664=== RUN TestService_cleanupPendingClosuresHandler665=== PAUSE TestService_cleanupPendingClosuresHandler666=== RUN TestService_createPendingClosureHandler667=== PAUSE TestService_createPendingClosureHandler668=== RUN TestService_verifyS3Integrity669=== PAUSE TestService_verifyS3Integrity670=== RUN TestCompleteMultipartUnregistered671=== PAUSE TestCompleteMultipartUnregistered672=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT673=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT674=== CONT TestReadProxyHead675=== CONT TestService_AuthMiddleware676=== CONT TestPushWaitsForSweepHoldingRow677=== CONT TestResolveDBConnectionString678=== CONT TestClientErrorHandling679=== RUN TestClientErrorHandling/InvalidStorePath680=== CONT TestTombstonedObjectOfferedWithoutWaiting681=== CONT TestClientFallsBackToClosures682=== CONT TestClientCADerivations683=== CONT TestGCBugBareHashReferences684=== PAUSE TestClientErrorHandling/InvalidStorePath685=== RUN TestClientErrorHandling/InvalidAuthToken686=== PAUSE TestClientErrorHandling/InvalidAuthToken687=== RUN TestClientErrorHandling/ServerNotAvailable688=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock689=== PAUSE TestClientErrorHandling/ServerNotAvailable690=== CONT TestClientPushesUseOnePush691=== RUN TestResolveDBConnectionString/flag_wins692=== PAUSE TestResolveDBConnectionString/flag_wins693=== RUN TestResolveDBConnectionString/file_when_flag_empty694=== PAUSE TestResolveDBConnectionString/file_when_flag_empty695=== RUN TestResolveDBConnectionString/missing_file_is_an_error696=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error697=== RUN TestResolveDBConnectionString/PGHOST_allows_empty698=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty699=== RUN TestResolveDBConnectionString/nothing_configured700=== PAUSE TestResolveDBConnectionString/nothing_configured701=== CONT TestPinProtectsFromGC702--- PASS: TestReadProxyHead (0.43s)703=== CONT TestClientSharedPathCommittedMidPush7042026/10/01 13:03:33 INFO Received uploads request method=POST path=/api/pending_closures7052026/10/01 13:03:33 INFO Received uploads request method=POST path=/api/pending_closures7062026/10/01 13:03:33 INFO Received uploads request method=POST path=/api/pending_closures7072026/10/01 13:03:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)7082026/10/01 13:03:33 INFO Uploading dx5n26qdbnkwsbfgnpbqdr6csbkx6sfn-b (248B)7092026/10/01 13:03:33 INFO Uploading h0z113hdpab1nl1ia8wh7c6kwms8aaq3-shared-dep (136B)7102026/10/01 13:03:33 WARN Failed to register uploaded object key=dx5n26qdbnkwsbfgnpbqdr6csbkx6sfn.ls error="server returned 404: 404 page not found\n"7112026/10/01 13:03:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7122026/10/01 13:03:33 WARN Failed to register uploaded object key=nar/03rbklhx9bi1kg7zx1yhkc2jb2iy1r1bjyzk1jyq5ngll0l92v90.nar.zst error="server returned 404: 404 page not found\n"7132026/10/01 13:03:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7142026/10/01 13:03:33 WARN Failed to register uploaded object key=5q2sgl10vg66f5s6y46zlbyy2094iq1a.ls error="server returned 404: 404 page not found\n"7152026/10/01 13:03:33 WARN Failed to register uploaded object key=h0z113hdpab1nl1ia8wh7c6kwms8aaq3.ls error="server returned 404: 404 page not found\n"7162026/10/01 13:03:33 INFO Signed narinfos id=1 count=27172026/10/01 13:03:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign7182026/10/01 13:03:33 INFO Signed narinfos id=2 count=27192026/10/01 13:03:33 INFO Uploading 4 narinfos7202026/10/01 13:03:33 WARN Failed to register uploaded object key=h0z113hdpab1nl1ia8wh7c6kwms8aaq3.narinfo error="server returned 404: 404 page not found\n"7212026/10/01 13:03:33 WARN Failed to register uploaded object key=5q2sgl10vg66f5s6y46zlbyy2094iq1a.narinfo error="server returned 404: 404 page not found\n"7222026/10/01 13:03:33 WARN Failed to register uploaded object key=dx5n26qdbnkwsbfgnpbqdr6csbkx6sfn.narinfo error="server returned 404: 404 page not found\n"7232026/10/01 13:03:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7242026/10/01 13:03:33 WARN Failed to register uploaded object key=h0z113hdpab1nl1ia8wh7c6kwms8aaq3.narinfo error="server returned 404: 404 page not found\n"7252026/10/01 13:03:33 INFO Completed upload id=17262026/10/01 13:03:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete7272026/10/01 13:03:33 INFO Completed upload id=27282026/10/01 13:03:33 INFO Upload complete. (93ms)729=== NAME TestClientFallsBackToClosures730 client_pushes_test.go:112: Retrieved narinfo from S3:731 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientFallsBackToClosures2264391655/001/store/h0z113hdpab1nl1ia8wh7c6kwms8aaq3-shared-dep732 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst733 Compression: zstd734 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82735 NarSize: 136736 References: 737 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n738 client_pushes_test.go:112: Retrieved narinfo from S3:739 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientFallsBackToClosures2264391655/001/store/5q2sgl10vg66f5s6y46zlbyy2094iq1a-a740 URL: nar/03rbklhx9bi1kg7zx1yhkc2jb2iy1r1bjyzk1jyq5ngll0l92v90.nar.zst741 Compression: zstd742 NarHash: sha256:03rbklhx9bi1kg7zx1yhkc2jb2iy1r1bjyzk1jyq5ngll0l92v90743 NarSize: 248744 References: /nix/var/nix/builds/nix-17449-2882215670/TestClientFallsBackToClosures2264391655/001/store/h0z113hdpab1nl1ia8wh7c6kwms8aaq3-shared-dep745 CA: text:sha256:01m3clcld9179i2c02vpgxfhi0gn6gpr6hcdvhfxj6mm6l4s3v01746 client_pushes_test.go:112: Retrieved narinfo from S3:747 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientFallsBackToClosures2264391655/001/store/dx5n26qdbnkwsbfgnpbqdr6csbkx6sfn-b748 URL: nar/03rbklhx9bi1kg7zx1yhkc2jb2iy1r1bjyzk1jyq5ngll0l92v90.nar.zst749 Compression: zstd750 NarHash: sha256:03rbklhx9bi1kg7zx1yhkc2jb2iy1r1bjyzk1jyq5ngll0l92v90751 NarSize: 248752 References: /nix/var/nix/builds/nix-17449-2882215670/TestClientFallsBackToClosures2264391655/001/store/h0z113hdpab1nl1ia8wh7c6kwms8aaq3-shared-dep753 CA: text:sha256:01m3clcld9179i2c02vpgxfhi0gn6gpr6hcdvhfxj6mm6l4s3v017542026/10/01 13:03:33 INFO Received push request method=POST path=/api/pushes7552026/10/01 13:03:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)7562026/10/01 13:03:33 INFO Uploading xjrvvi1f6glz5difz26pk8vibbja9h0k-a (248B)7572026/10/01 13:03:33 INFO Uploading pbgq2v1xwhsp0lklz5f2yv344p2jprrs-shared-dep (136B)7582026/10/01 13:03:33 WARN Failed to register uploaded object key=xjrvvi1f6glz5difz26pk8vibbja9h0k.ls error="server returned 404: 404 page not found\n"7592026/10/01 13:03:33 WARN Failed to register uploaded object key=r3rvhnjy5f6km8zml05vln49k7skn7aa.ls error="server returned 404: 404 page not found\n"7602026/10/01 13:03:33 WARN Failed to register uploaded object key=pbgq2v1xwhsp0lklz5f2yv344p2jprrs.ls error="server returned 404: 404 page not found\n"7612026/10/01 13:03:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7622026/10/01 13:03:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7632026/10/01 13:03:33 WARN Failed to register uploaded object key=nar/160p9ya08a3yndpdh11lchqpaild1hfa28wg0ilgnwxzasaccbs6.nar.zst error="server returned 404: 404 page not found\n"7642026/10/01 13:03:33 INFO Signed narinfos id=1 count=37652026/10/01 13:03:33 INFO Uploading 3 narinfos766--- PASS: TestClientFallsBackToClosures (1.05s)767=== CONT TestCacheStatsHandler7682026/10/01 13:03:33 WARN Failed to register uploaded object key=xjrvvi1f6glz5difz26pk8vibbja9h0k.narinfo error="server returned 404: 404 page not found\n"7692026/10/01 13:03:33 WARN Failed to register uploaded object key=r3rvhnjy5f6km8zml05vln49k7skn7aa.narinfo error="server returned 404: 404 page not found\n"7702026/10/01 13:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete7712026/10/01 13:03:33 WARN Failed to register uploaded object key=pbgq2v1xwhsp0lklz5f2yv344p2jprrs.narinfo error="server returned 404: 404 page not found\n"7722026/10/01 13:03:33 INFO Upload complete. (101ms)773=== NAME TestClientPushesUseOnePush774 client_pushes_test.go:97: Retrieved narinfo from S3:775 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientPushesUseOnePush2066182157/001/store/pbgq2v1xwhsp0lklz5f2yv344p2jprrs-shared-dep776 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst777 Compression: zstd778 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82779 NarSize: 136780 References: 781 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n782 client_pushes_test.go:97: Retrieved narinfo from S3:783 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientPushesUseOnePush2066182157/001/store/xjrvvi1f6glz5difz26pk8vibbja9h0k-a784 URL: nar/160p9ya08a3yndpdh11lchqpaild1hfa28wg0ilgnwxzasaccbs6.nar.zst785 Compression: zstd786 NarHash: sha256:160p9ya08a3yndpdh11lchqpaild1hfa28wg0ilgnwxzasaccbs6787 NarSize: 248788 References: /nix/var/nix/builds/nix-17449-2882215670/TestClientPushesUseOnePush2066182157/001/store/pbgq2v1xwhsp0lklz5f2yv344p2jprrs-shared-dep789 CA: text:sha256:1gzq1bcaqczj8i2kv134avqbgfgiladaqgzr5k3psxq6pakhzgyf790 client_pushes_test.go:97: Retrieved narinfo from S3:791 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientPushesUseOnePush2066182157/001/store/r3rvhnjy5f6km8zml05vln49k7skn7aa-b792 URL: nar/160p9ya08a3yndpdh11lchqpaild1hfa28wg0ilgnwxzasaccbs6.nar.zst793 Compression: zstd794 NarHash: sha256:160p9ya08a3yndpdh11lchqpaild1hfa28wg0ilgnwxzasaccbs6795 NarSize: 248796 References: /nix/var/nix/builds/nix-17449-2882215670/TestClientPushesUseOnePush2066182157/001/store/pbgq2v1xwhsp0lklz5f2yv344p2jprrs-shared-dep797 CA: text:sha256:1gzq1bcaqczj8i2kv134avqbgfgiladaqgzr5k3psxq6pakhzgyf798--- PASS: TestClientPushesUseOnePush (1.10s)799=== CONT TestCacheConfigHandler800=== RUN TestCacheConfigHandler/full_config,_no_issuer801=== PAUSE TestCacheConfigHandler/full_config,_no_issuer802=== RUN TestCacheConfigHandler/no_cache_url_configured803=== PAUSE TestCacheConfigHandler/no_cache_url_configured804=== RUN TestCacheConfigHandler/no_signing_keys805=== PAUSE TestCacheConfigHandler/no_signing_keys806=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator807=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator808=== CONT TestClientWithDependencies809=== NAME TestPinProtectsFromGC810 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-17449-2882215670/TestPinProtectsFromGC2249658555/001/store/pa2d7b2xaxa208safpgajhd9zvxa2kmy-pinned-file.txt811 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-17449-2882215670/TestPinProtectsFromGC2249658555/001/store/5q5xhf30yky74dfd305kgx7w8qn1vsgr-unpinned-file.txt8122026/10/01 13:03:33 INFO Received push request method=POST path=/api/pushes813--- PASS: TestPushWaitsForSweepHoldingRow (1.43s)814=== CONT TestClientMultipleUploads8152026/10/01 13:03:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8162026/10/01 13:03:33 INFO Uploading pa2d7b2xaxa208safpgajhd9zvxa2kmy-pinned-file.txt (128B)8172026/10/01 13:03:33 WARN Failed to register uploaded object key=pa2d7b2xaxa208safpgajhd9zvxa2kmy.ls error="server returned 404: 404 page not found\n"8182026/10/01 13:03:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8192026/10/01 13:03:33 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"8202026/10/01 13:03:33 INFO Signed narinfos id=1 count=18212026/10/01 13:03:33 INFO Uploading 1 narinfos822--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.45s)823=== CONT TestService_ReadScope_PublicByDefault8242026/10/01 13:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete8252026/10/01 13:03:33 WARN Failed to register uploaded object key=pa2d7b2xaxa208safpgajhd9zvxa2kmy.narinfo error="server returned 404: 404 page not found\n"8262026/10/01 13:03:33 INFO Upload complete. (96ms)8272026/10/01 13:03:34 INFO Received push request method=POST path=/api/pushes8282026/10/01 13:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8292026/10/01 13:03:34 INFO Uploading 5q5xhf30yky74dfd305kgx7w8qn1vsgr-unpinned-file.txt (128B)8302026/10/01 13:03:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"831--- PASS: TestService_AuthMiddleware (1.56s)832=== CONT TestClientIntegration8332026/10/01 13:03:34 WARN Failed to register uploaded object key=5q5xhf30yky74dfd305kgx7w8qn1vsgr.ls error="server returned 404: 404 page not found\n"8342026/10/01 13:03:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"8352026/10/01 13:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8362026/10/01 13:03:34 INFO Signed narinfos id=2 count=18372026/10/01 13:03:34 INFO Uploading 1 narinfos8382026/10/01 13:03:34 INFO Received complete push request method=POST path=/api/pushes/2/complete8392026/10/01 13:03:34 WARN Failed to register uploaded object key=5q5xhf30yky74dfd305kgx7w8qn1vsgr.narinfo error="server returned 404: 404 page not found\n"8402026/10/01 13:03:34 INFO Upload complete. (68ms)8412026/10/01 13:03:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures8422026/10/01 13:03:34 INFO Garbage collection started8432026/10/01 13:03:34 INFO Aborted multipart uploads count=0 kept=08442026/10/01 13:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period8452026/10/01 13:03:34 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=08462026/10/01 13:03:34 INFO Vacuumed table table=pending_closures8472026/10/01 13:03:34 INFO Vacuumed table table=pending_objects8482026/10/01 13:03:34 INFO Vacuumed table table=multipart_uploads8492026/10/01 13:03:34 INFO Vacuumed table table=closures8502026/10/01 13:03:34 INFO Vacuumed table table=objects851=== NAME TestClientCADerivations852 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-17449-2882215670/TestClientCADerivations2641529528/001/store/bcklr3wamj177hfaf48bzznzr27nimyf-ca-test8532026/10/01 13:03:34 INFO Received uploads request method=POST path=/api/pending_closures854 client_ca_test.go:139: Found 1 dependencies (including self)855--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.78s)856=== CONT TestService_RequireScope_OIDC8572026/10/01 13:03:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50527/oidc8582026/10/01 13:03:34 INFO Received push request method=POST path=/api/pushes8592026/10/01 13:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8602026/10/01 13:03:34 INFO Uploading bcklr3wamj177hfaf48bzznzr27nimyf-ca-test (144B)8612026/10/01 13:03:34 WARN Failed to register uploaded object key=bcklr3wamj177hfaf48bzznzr27nimyf.ls error="server returned 404: 404 page not found\n"8622026/10/01 13:03:34 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"8632026/10/01 13:03:34 WARN Failed to register uploaded object key=log/98vqz2cpq4pyw3r565vyzvfad5d91yn9-ca-test.drv error="server returned 404: 404 page not found\n"8642026/10/01 13:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/01 13:03:34 INFO Signed narinfos id=1 count=18662026/10/01 13:03:34 INFO Uploading 1 narinfos8672026/10/01 13:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete8682026/10/01 13:03:34 WARN Failed to register uploaded object key=bcklr3wamj177hfaf48bzznzr27nimyf.narinfo error="server returned 404: 404 page not found\n"8692026/10/01 13:03:34 INFO Upload complete. (156ms)870=== NAME TestClientCADerivations871 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientCADerivations2641529528/001/store/bcklr3wamj177hfaf48bzznzr27nimyf-ca-test872 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst873 Compression: zstd874 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n875 NarSize: 144876 References: 877 Deriver: /nix/var/nix/builds/nix-17449-2882215670/TestClientCADerivations2641529528/001/store/98vqz2cpq4pyw3r565vyzvfad5d91yn9-ca-test.drv878 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n879 client_ca_test.go:185: Checking for realisation files in S3...880 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations881 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache882 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket9?endpoint=http://localhost:50438®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-17449-2882215670/TestClientCADerivations2641529528/001/store'883 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 1884--- PASS: TestClientCADerivations (2.04s)885=== CONT TestService_AuthMiddleware_OIDC8862026/10/01 13:03:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50543/oidc887--- PASS: TestGCBugBareHashReferences (2.14s)888=== CONT TestService_ReadAuthMiddleware889--- PASS: TestCacheStatsHandler (1.21s)890=== CONT TestService_AuthMiddleware_MTLSBoundSubjects8912026/10/01 13:03:34 INFO Received push request method=POST path=/api/pushes8922026/10/01 13:03:34 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8932026/10/01 13:03:34 INFO Uploading kdzq7h4yml4r11j20y4sf2kwr0xirj3v-top (256B)8942026/10/01 13:03:34 INFO Uploading hvjf1vm6ffq83c6xzdxd7s6wnsv5m4zw-shared-dep (136B)8952026/10/01 13:03:34 WARN Failed to register uploaded object key=kdzq7h4yml4r11j20y4sf2kwr0xirj3v.ls error="server returned 404: 404 page not found\n"8962026/10/01 13:03:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8972026/10/01 13:03:34 WARN Failed to register uploaded object key=hvjf1vm6ffq83c6xzdxd7s6wnsv5m4zw.ls error="server returned 404: 404 page not found\n"8982026/10/01 13:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8992026/10/01 13:03:34 WARN Failed to register uploaded object key=nar/0gnjy6ymqnd5ksb8hjhqm1sdik5vfp7xfqhzak616av3xxlg7mki.nar.zst error="server returned 404: 404 page not found\n"9002026/10/01 13:03:34 INFO Signed narinfos id=1 count=29012026/10/01 13:03:34 INFO Uploading 2 narinfos9022026/10/01 13:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete9032026/10/01 13:03:34 WARN Failed to register uploaded object key=hvjf1vm6ffq83c6xzdxd7s6wnsv5m4zw.narinfo error="server returned 404: 404 page not found\n"9042026/10/01 13:03:34 WARN Failed to register uploaded object key=kdzq7h4yml4r11j20y4sf2kwr0xirj3v.narinfo error="server returned 404: 404 page not found\n"9052026/10/01 13:03:34 INFO Upload complete. (135ms)906=== NAME TestClientSharedPathCommittedMidPush907 client_integration_test.go:680: Retrieved narinfo from S3:908 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientSharedPathCommittedMidPush3609301620/001/store/hvjf1vm6ffq83c6xzdxd7s6wnsv5m4zw-shared-dep909 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst910 Compression: zstd911 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82912 NarSize: 136913 References: 914 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n915 client_integration_test.go:680: Retrieved narinfo from S3:916 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientSharedPathCommittedMidPush3609301620/001/store/kdzq7h4yml4r11j20y4sf2kwr0xirj3v-top917 URL: nar/0gnjy6ymqnd5ksb8hjhqm1sdik5vfp7xfqhzak616av3xxlg7mki.nar.zst918 Compression: zstd919 NarHash: sha256:0gnjy6ymqnd5ksb8hjhqm1sdik5vfp7xfqhzak616av3xxlg7mki920 NarSize: 256921 References: /nix/var/nix/builds/nix-17449-2882215670/TestClientSharedPathCommittedMidPush3609301620/001/store/hvjf1vm6ffq83c6xzdxd7s6wnsv5m4zw-shared-dep922 CA: text:sha256:15phdp7ci1qs9ncbrf63l920p584np27bg2h0yw02z6ijd29x6k5923--- PASS: TestClientSharedPathCommittedMidPush (1.98s)924=== CONT TestService_AuthMiddleware_MTLSProxyHeader925=== NAME TestClientWithDependencies926 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-17449-2882215670/TestClientWithDependencies3243335361/001/store/hc38g5wx5f25vmq5bscihwwslxnznz3k-test-script927=== NAME TestClientIntegration928 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-17449-2882215670/TestClientIntegration2390565605/002/store/abvq883hzf0za46f9dn6rhqxgbi1jv9r-test-file.txt929=== NAME TestClientWithDependencies930 client_integration_test.go:615: Found 1 dependencies (including self)9312026/10/01 13:03:35 INFO Received push request method=POST path=/api/pushes9322026/10/01 13:03:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9332026/10/01 13:03:35 INFO Uploading abvq883hzf0za46f9dn6rhqxgbi1jv9r-test-file.txt (152B)9342026/10/01 13:03:35 INFO Received push request method=POST path=/api/pushes9352026/10/01 13:03:35 WARN Failed to register uploaded object key=abvq883hzf0za46f9dn6rhqxgbi1jv9r.ls error="server returned 404: 404 page not found\n"9362026/10/01 13:03:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9372026/10/01 13:03:35 INFO Uploading hc38g5wx5f25vmq5bscihwwslxnznz3k-test-script (136B)9382026/10/01 13:03:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9392026/10/01 13:03:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9402026/10/01 13:03:35 INFO Signed narinfos id=1 count=19412026/10/01 13:03:35 INFO Uploading 1 narinfos9422026/10/01 13:03:35 WARN Failed to register uploaded object key=hc38g5wx5f25vmq5bscihwwslxnznz3k.ls error="server returned 404: 404 page not found\n"9432026/10/01 13:03:35 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9442026/10/01 13:03:35 INFO Received complete push request method=POST path=/api/pushes/1/complete9452026/10/01 13:03:35 WARN Failed to register uploaded object key=abvq883hzf0za46f9dn6rhqxgbi1jv9r.narinfo error="server returned 404: 404 page not found\n"9462026/10/01 13:03:35 WARN Failed to register uploaded object key=log/a10dx1pi3cjpa0pkv9skm0qplcm2zr40-test-script.drv error="server returned 404: 404 page not found\n"9472026/10/01 13:03:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9482026/10/01 13:03:35 INFO Signed narinfos id=1 count=19492026/10/01 13:03:35 INFO Uploading 1 narinfos9502026/10/01 13:03:35 INFO Upload complete. (132ms)9512026/10/01 13:03:35 INFO Received complete push request method=POST path=/api/pushes/1/complete9522026/10/01 13:03:35 WARN Failed to register uploaded object key=hc38g5wx5f25vmq5bscihwwslxnznz3k.narinfo error="server returned 404: 404 page not found\n"9532026/10/01 13:03:35 INFO Upload complete. (124ms)954 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-17449-2882215670/TestClientWithDependencies3243335361/001/store) requires matching store prefix9552026/10/01 13:03:35 INFO All 1 paths already cached956=== NAME TestClientIntegration957 client_integration_test.go:312: Retrieved narinfo from S3:958 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestClientIntegration2390565605/002/store/abvq883hzf0za46f9dn6rhqxgbi1jv9r-test-file.txt959 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst960 Compression: zstd961 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1962 NarSize: 152963 References: 964 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1965 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)966 client_integration_test.go:313: Decompressed .ls content (64 bytes):967 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}968 client_integration_test.go:316: Testing garbage collection...9692026/10/01 13:03:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures9702026/10/01 13:03:35 INFO Garbage collection started9712026/10/01 13:03:35 INFO Aborted multipart uploads count=0 kept=09722026/10/01 13:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period973--- PASS: TestClientWithDependencies (1.85s)974=== CONT TestLeadElectsOneAndHandsOver975=== NAME TestClientMultipleUploads976 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-17449-2882215670/TestClientMultipleUploads3283773199/001/store/r84sl5457isi8f8hyamklb7r4xqqpxzs-test-file-0.txt9772026/10/01 13:03:35 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=0978--- PASS: TestService_ReadScope_PublicByDefault (1.53s)979=== CONT TestConnectWaitsForAPeerMigration9802026/10/01 13:03:35 INFO Vacuumed table table=pending_closures9812026/10/01 13:03:35 INFO Vacuumed table table=pending_objects9822026/10/01 13:03:35 INFO Vacuumed table table=multipart_uploads9832026/10/01 13:03:35 INFO Vacuumed table table=closures984=== NAME TestClientMultipleUploads985 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-17449-2882215670/TestClientMultipleUploads3283773199/001/store/3z0089cwdismb7in88nyphprxhs3g8v3-test-file-1.txt9862026/10/01 13:03:35 INFO Vacuumed table table=objects987 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-17449-2882215670/TestClientMultipleUploads3283773199/001/store/56g4y7v2rdnfwgd9fr23whzdl4lr3c07-test-file-2.txt9882026/10/01 13:03:35 INFO Received push request method=POST path=/api/pushes989=== RUN TestService_RequireScope_OIDC/builder_may_write990=== PAUSE TestService_RequireScope_OIDC/builder_may_write991=== RUN TestService_RequireScope_OIDC/builder_may_not_admin992=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin993=== RUN TestService_RequireScope_OIDC/ops_may_admin994=== PAUSE TestService_RequireScope_OIDC/ops_may_admin995=== RUN TestService_RequireScope_OIDC/ops_may_not_write996=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write997=== RUN TestService_RequireScope_OIDC/reader_may_not_write998=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write999=== RUN TestService_RequireScope_OIDC/static_token_may_admin1000=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1001=== RUN TestService_RequireScope_OIDC/static_token_may_write1002=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1003=== RUN TestService_RequireScope_OIDC/reader_may_read1004=== PAUSE TestService_RequireScope_OIDC/reader_may_read1005=== RUN TestService_RequireScope_OIDC/writer_implies_read1006=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1007=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1008=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1009=== CONT TestDeduplicatedObjectsRecordedAsPending10102026/10/01 13:03:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10112026/10/01 13:03:35 INFO Uploading r84sl5457isi8f8hyamklb7r4xqqpxzs-test-file-0.txt (160B)10122026/10/01 13:03:35 INFO Uploading 3z0089cwdismb7in88nyphprxhs3g8v3-test-file-1.txt (160B)10132026/10/01 13:03:35 INFO Uploading 56g4y7v2rdnfwgd9fr23whzdl4lr3c07-test-file-2.txt (160B)10142026/10/01 13:03:35 WARN Failed to register uploaded object key=3z0089cwdismb7in88nyphprxhs3g8v3.ls error="server returned 404: 404 page not found\n"10152026/10/01 13:03:35 WARN Failed to register uploaded object key=56g4y7v2rdnfwgd9fr23whzdl4lr3c07.ls error="server returned 404: 404 page not found\n"10162026/10/01 13:03:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10172026/10/01 13:03:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10182026/10/01 13:03:35 WARN Failed to register uploaded object key=r84sl5457isi8f8hyamklb7r4xqqpxzs.ls error="server returned 404: 404 page not found\n"10192026/10/01 13:03:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/10/01 13:03:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10212026/10/01 13:03:35 INFO Signed narinfos id=1 count=310222026/10/01 13:03:35 INFO Uploading 3 narinfos10232026/10/01 13:03:35 WARN Failed to register uploaded object key=r84sl5457isi8f8hyamklb7r4xqqpxzs.narinfo error="server returned 404: 404 page not found\n"10242026/10/01 13:03:35 WARN Failed to register uploaded object key=3z0089cwdismb7in88nyphprxhs3g8v3.narinfo error="server returned 404: 404 page not found\n"10252026/10/01 13:03:35 INFO Received complete push request method=POST path=/api/pushes/1/complete10262026/10/01 13:03:35 WARN Failed to register uploaded object key=56g4y7v2rdnfwgd9fr23whzdl4lr3c07.narinfo error="server returned 404: 404 page not found\n"10272026/10/01 13:03:35 INFO Upload complete. (97ms)1028=== NAME TestClientMultipleUploads1029 client_integration_test.go:369: Uploaded 3 paths in 132.636542ms1030--- PASS: TestClientMultipleUploads (1.82s)1031=== CONT TestGCSweepSkipsPendingObjects1032=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1033=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1034=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1035=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1036=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1037=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1038=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1039=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1040=== CONT TestCompletedNarNotReofferedAcrossClosures1041--- PASS: TestService_ReadAuthMiddleware (1.40s)1042=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10432026/10/01 13:03:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=010442026/10/01 13:03:36 INFO Received create pin request method=POST path=/api/pins/myapp10452026/10/01 13:03:36 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-17449-2882215670/TestPinProtectsFromGC2249658555/001/store/pa2d7b2xaxa208safpgajhd9zvxa2kmy-pinned-file.txt narinfo_key=pa2d7b2xaxa208safpgajhd9zvxa2kmy.narinfo10462026/10/01 13:03:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures10472026/10/01 13:03:36 INFO Garbage collection started10482026/10/01 13:03:36 INFO Aborted multipart uploads count=0 kept=010492026/10/01 13:03:36 WARN Force mode enabled - objects will be deleted immediately without grace period10502026/10/01 13:03:36 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=010512026/10/01 13:03:36 INFO Vacuumed table table=pending_closures10522026/10/01 13:03:36 INFO Vacuumed table table=pending_objects10532026/10/01 13:03:36 INFO Vacuumed table table=multipart_uploads10542026/10/01 13:03:36 INFO Vacuumed table table=closures10552026/10/01 13:03:36 INFO Vacuumed table table=objects10562026/10/01 13:03:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10572026/10/01 13:03:36 WARN mTLS auth: bound subjects configured but subject DN unavailable10582026/10/01 13:03:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1059--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.46s)1060=== CONT TestCompleteMultipartUnregistered1061--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.50s)1062=== CONT TestService_verifyS3Integrity10632026/10/01 13:03:36 INFO lead: acquired remote=192.0.2.1:123410642026/10/01 13:03:36 INFO Received uploads request method=POST path=/api/pending_closures1065--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.22s)1066=== CONT TestService_createPendingClosureHandler10672026/10/01 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures10682026/10/01 13:03:37 INFO Aborted multipart uploads count=0 kept=010692026/10/01 13:03:37 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/10/01 13:03:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010712026/10/01 13:03:37 INFO Vacuumed table table=pending_closures10722026/10/01 13:03:37 INFO Vacuumed table table=pending_objects10732026/10/01 13:03:37 INFO Vacuumed table table=multipart_uploads10742026/10/01 13:03:37 INFO Vacuumed table table=closures10752026/10/01 13:03:37 INFO Vacuumed table table=objects1076--- PASS: TestGCSweepSkipsPendingObjects (1.42s)1077=== CONT TestLeadEndsOnShutdown10782026/10/01 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures10792026/10/01 13:03:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01080=== NAME TestClientIntegration1081 client_integration_test.go:323: Objects in database after GC:1082 client_integration_test.go:323: Successfully deleted all objects with GC --force1083--- PASS: TestClientIntegration (3.44s)1084=== CONT TestService_cleanupPendingClosuresHandler10852026/10/01 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures1086--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.54s)1087=== CONT TestUploadHandlersRejectOversizedBody1088=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1089=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1090=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1091=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1092=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1093=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1094=== CONT TestGCAdvisoryLockBlocksConcurrentRun10952026/10/01 13:03:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10962026/10/01 13:03:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1097--- PASS: TestCompleteMultipartUnregistered (1.51s)1098=== CONT TestUploadHandlersRejectInvalidKeys1099=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1100=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1101=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1102=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1103=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1104=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1105=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1106=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1107=== CONT TestIsValidUploadKey1108=== RUN TestIsValidUploadKey/narinfo1109=== PAUSE TestIsValidUploadKey/narinfo1110=== RUN TestIsValidUploadKey/nar_zst1111=== PAUSE TestIsValidUploadKey/nar_zst1112=== RUN TestIsValidUploadKey/nar_xz1113=== PAUSE TestIsValidUploadKey/nar_xz1114=== RUN TestIsValidUploadKey/nar_plain1115=== PAUSE TestIsValidUploadKey/nar_plain1116=== RUN TestIsValidUploadKey/listing1117=== PAUSE TestIsValidUploadKey/listing1118=== RUN TestIsValidUploadKey/build_log1119=== PAUSE TestIsValidUploadKey/build_log1120=== RUN TestIsValidUploadKey/build_log_home-manager_file1121=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1122=== RUN TestIsValidUploadKey/build_log_plus_in_name1123=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1124=== RUN TestIsValidUploadKey/build_log_question_mark1125=== PAUSE TestIsValidUploadKey/build_log_question_mark1126=== RUN TestIsValidUploadKey/build_log_equals1127=== PAUSE TestIsValidUploadKey/build_log_equals1128=== RUN TestIsValidUploadKey/realisation1129=== PAUSE TestIsValidUploadKey/realisation1130=== RUN TestIsValidUploadKey/realisation_plus_in_output1131=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1132=== RUN TestIsValidUploadKey/nix-cache-info1133=== PAUSE TestIsValidUploadKey/nix-cache-info1134=== RUN TestIsValidUploadKey/index.html1135=== PAUSE TestIsValidUploadKey/index.html1136=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1137=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1138=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1139=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1140=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1141=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1142=== RUN TestIsValidUploadKey/traversal1143=== PAUSE TestIsValidUploadKey/traversal1144=== RUN TestIsValidUploadKey/traversal_nar1145=== PAUSE TestIsValidUploadKey/traversal_nar1146=== RUN TestIsValidUploadKey/absolute1147=== PAUSE TestIsValidUploadKey/absolute1148=== RUN TestIsValidUploadKey/empty_key1149=== PAUSE TestIsValidUploadKey/empty_key1150=== RUN TestIsValidUploadKey/unknown_type1151=== PAUSE TestIsValidUploadKey/unknown_type1152=== CONT TestSkippedUploadsHandler11532026/10/01 13:03:37 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001154--- PASS: TestSkippedUploadsHandler (0.00s)1155=== CONT TestParseSize1156--- PASS: TestParseSize (0.00s)1157=== CONT TestPendingClosureWriteTimeout1158=== RUN TestPendingClosureWriteTimeout/empty1159=== PAUSE TestPendingClosureWriteTimeout/empty1160=== RUN TestPendingClosureWriteTimeout/400_objects1161=== PAUSE TestPendingClosureWriteTimeout/400_objects1162=== RUN TestPendingClosureWriteTimeout/670k_objects1163=== PAUSE TestPendingClosureWriteTimeout/670k_objects1164=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1165=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1166=== CONT TestService_Rustfstest11672026/10/01 13:03:37 INFO lead: released remote=192.0.2.1:123411682026/10/01 13:03:37 INFO lead: acquired remote=192.0.2.1:123411692026/10/01 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures1170=== NAME TestPinProtectsFromGC1171 client_integration_test.go:840: Pin successfully protected closure from garbage collection1172--- PASS: TestPinProtectsFromGC (5.72s)1173=== CONT TestProxyWriteTimeout1174=== RUN TestProxyWriteTimeout/narinfo1175=== PAUSE TestProxyWriteTimeout/narinfo1176=== RUN TestProxyWriteTimeout/1_GiB_nar1177=== PAUSE TestProxyWriteTimeout/1_GiB_nar1178=== RUN TestProxyWriteTimeout/10_GiB_nar1179=== PAUSE TestProxyWriteTimeout/10_GiB_nar1180=== RUN TestProxyWriteTimeout/unknown_size1181=== PAUSE TestProxyWriteTimeout/unknown_size1182=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11832026/10/01 13:03:38 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/01 13:03:38 INFO Received uploads request method=POST path=/api/pending_closures11852026/10/01 13:03:38 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/01 13:03:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11872026/10/01 13:03:38 INFO lead: acquired remote=192.0.2.1:123411882026/10/01 13:03:38 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLjU4NzdiNTExLTczNGUtNDU2NC1hOTI2LTFhMWE3ZjhjMjY5MHgxNzkwODU5ODE3MzY0NjgwMDAw parts=1211892026/10/01 13:03:38 INFO Received uploads request method=POST path=/api/pending_closures1190--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.94s)1191=== CONT TestPresignedUploadRegisteredBeforeCommit11922026/10/01 13:03:39 INFO lead: released remote=192.0.2.1:12341193--- PASS: TestLeadElectsOneAndHandsOver (3.53s)1194=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11952026/10/01 13:03:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11962026/10/01 13:03:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLjI2ZDE5ZDc1LTZlMWEtNDFkMi04MGUxLWY5OTMxNjU5MzZhY3gxNzkwODU5ODE3OTczNTk3MDAw parts=1011972026/10/01 13:03:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11982026/10/01 13:03:39 INFO Completed upload id=111992026/10/01 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures12002026/10/01 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures12012026/10/01 13:03:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12022026/10/01 13:03:39 WARN Found objects in DB but missing from S3, will re-upload count=11203--- PASS: TestService_verifyS3Integrity (2.90s)1204=== CONT TestRedundantMultipartUpload12052026/10/01 13:03:39 INFO Received cleanup request method=DELETE path=/api/pending_closures12062026/10/01 13:03:39 INFO Aborted multipart uploads count=0 kept=012072026/10/01 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures12082026/10/01 13:03:39 INFO Received cleanup request method=DELETE path=/api/pending_closures12092026/10/01 13:03:39 INFO Aborted multipart uploads count=1 kept=012102026/10/01 13:03:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12112026-10-01 13:03:39.585 UTC [17732] ERROR: Closure does not exist: id=112122026-10-01 13:03:39.585 UTC [17732] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12132026-10-01 13:03:39.585 UTC [17732] STATEMENT: -- name: CommitPendingClosure :exec1214 SELECT commit_pending_closure($1::bigint)1215 1216--- PASS: TestService_cleanupPendingClosuresHandler (2.07s)1217=== CONT TestFailedS3DeleteKeepsTombstone12182026/10/01 13:03:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1219--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.17s)1220=== CONT TestReadProxyRangeRequest12212026/10/01 13:03:39 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLmM0NmYxNzljLWQ5NWMtNGVhMy1iOGQyLTRhNmJiM2JjZTllOXgxNzkwODU5ODE4MzAzMDA3MDAw parts=1012222026/10/01 13:03:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12232026/10/01 13:03:39 INFO Completed upload id=112242026/10/01 13:03:39 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012252026/10/01 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures12262026/10/01 13:03:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures12272026/10/01 13:03:39 INFO Aborted multipart uploads count=0 kept=012282026/10/01 13:03:39 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=012292026/10/01 13:03:39 INFO Vacuumed table table=pending_closures12302026/10/01 13:03:39 INFO lead: released remote=192.0.2.1:12341231--- PASS: TestLeadEndsOnShutdown (2.67s)1232=== CONT TestReadRedirectKeepsNarinfoProxied12332026/10/01 13:03:39 INFO Vacuumed table table=pending_objects12342026/10/01 13:03:39 INFO Vacuumed table table=multipart_uploads12352026/10/01 13:03:40 INFO Vacuumed table table=closures12362026/10/01 13:03:40 INFO Vacuumed table table=objects12372026/10/01 13:03:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001238--- PASS: TestService_createPendingClosureHandler (3.12s)1239=== CONT TestSweepRechecksPendingAfterLocking1240--- PASS: TestService_Rustfstest (2.36s)1241=== CONT TestPush_SignsNarinfosOfItsPendingObjects12422026/10/01 13:03:40 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/01 13:03:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12442026/10/01 13:03:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLmQzOTU4OTZmLWQwNjAtNDczZS05M2I1LWIwMzA3MzFiMjFjM3gxNzkwODU5ODIwNjUzNzU2MDAw12452026/10/01 13:03:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLmQzOTU4OTZmLWQwNjAtNDczZS05M2I1LWIwMzA3MzFiMjFjM3gxNzkwODU5ODIwNjUzNzU2MDAw parts=11246--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.68s)1247=== CONT TestReadRedirectNar12482026/10/01 13:03:41 INFO Received uploads request method=POST path=/api/pending_closures12492026/10/01 13:03:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12502026/10/01 13:03:41 INFO Received uploads request method=POST path=/api/pending_closures1251--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.41s)1252=== CONT TestGetExistingObjectsLocksRows12532026/10/01 13:03:41 INFO Received uploads request method=POST path=/api/pending_closures1254--- PASS: TestConnectWaitsForAPeerMigration (6.51s)1255=== CONT TestReadProxyDisabled12562026/10/01 13:03:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12572026/10/01 13:03:42 INFO Received uploads request method=POST path=/api/pending_closures12582026/10/01 13:03:42 INFO Received uploads request method=POST path=/api/pending_closures12592026/10/01 13:03:42 INFO Received uploads request method=POST path=/api/pending_closures12602026/10/01 13:03:42 INFO Aborted multipart uploads count=0 kept=012612026/10/01 13:03:42 WARN Force mode enabled - objects will be deleted immediately without grace period12622026/10/01 13:03:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12632026/10/01 13:03:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1264--- PASS: TestFailedS3DeleteKeepsTombstone (3.29s)1265=== CONT TestRegisterCompletedObjectNeedsPendingRow1266--- PASS: TestReadProxyRangeRequest (3.28s)1267=== CONT TestReadProxyRootRedirectsToIndexHTML1268--- PASS: TestReadRedirectKeepsNarinfoProxied (3.61s)1269=== CONT TestReadProxyConditionalGet12702026/10/01 13:03:43 INFO Aborted multipart uploads count=0 kept=012712026/10/01 13:03:43 WARN Force mode enabled - objects will be deleted immediately without grace period12722026/10/01 13:03:43 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=012732026/10/01 13:03:43 INFO Vacuumed table table=pending_closures12742026/10/01 13:03:43 INFO Vacuumed table table=pending_objects12752026/10/01 13:03:43 INFO Vacuumed table table=multipart_uploads12762026/10/01 13:03:43 INFO Vacuumed table table=closures12772026/10/01 13:03:43 INFO Vacuumed table table=objects1278--- PASS: TestSweepRechecksPendingAfterLocking (3.93s)1279=== CONT TestReadProxyOutlastsServerWriteTimeout12802026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes12812026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12822026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12832026/10/01 13:03:44 INFO Signed narinfos id=1 count=11284--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (4.11s)1285=== CONT TestService_NativeMTLS12862026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLjgwNmNlYWZmLWE2ZWItNDY1ZC05OWQ2LTRkOTllNWI3YjEyN3gxNzkwODU5ODIyMTM3OTk5MDAw parts=1212872026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures12882026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures1289--- PASS: TestReadRedirectNar (3.47s)1290=== CONT TestReadProxyInvalidPath1291--- PASS: TestGetExistingObjectsLocksRows (3.36s)1292=== CONT TestReadProxy4041293--- PASS: TestReadProxyDisabled (2.83s)1294=== CONT TestReadProxyNarStreaming12952026/10/01 13:03:45 WARN Rate limiter enabled after throttle name=s3-test rate=512962026/10/01 13:03:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1297=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1298 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101299 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001300--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.23s)1301=== CONT TestReadProxyNarinfoAlreadyDecompressed1302--- PASS: TestReadProxyConditionalGet (1.85s)1303=== CONT TestSweepSkipsRowsLockedByPush1304--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.67s)1305=== CONT TestReadProxyNarinfo13062026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13072026/10/01 13:03:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLjQxYmRkNTJiLTRjZmEtNDM5My04OGRiLTg1N2JiNmJlNWQ1OHgxNzkwODU5ODI0Mjg2NzQzMDAw error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13082026/10/01 13:03:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWQ1YzdkZDEtNWQ2YS00YjExLTk0YTAtMDNmNzk5NTBmNTUxLjM4ZWU2MzA0LWNjMzEtNDg5ZS1iNmE3LTQwOWU5MjcxMjczZngxNzkwODU5ODI0MjQ0NzUxMDAw parts=1213092026/10/01 13:03:45 INFO Received cleanup request method=DELETE path=/api/pending_closures13102026/10/01 13:03:45 INFO Aborted multipart uploads count=1 kept=01311--- PASS: TestRedundantMultipartUpload (6.44s)1312=== CONT TestIsValidCachePath1313=== RUN TestIsValidCachePath/narinfo1314=== PAUSE TestIsValidCachePath/narinfo1315=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1316=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1317=== RUN TestIsValidCachePath/nar_zst1318=== PAUSE TestIsValidCachePath/nar_zst1319=== RUN TestIsValidCachePath/nar_xz1320=== PAUSE TestIsValidCachePath/nar_xz1321=== RUN TestIsValidCachePath/nar_bz21322=== PAUSE TestIsValidCachePath/nar_bz21323=== RUN TestIsValidCachePath/nar_uncompressed1324=== PAUSE TestIsValidCachePath/nar_uncompressed1325=== RUN TestIsValidCachePath/ls1326=== PAUSE TestIsValidCachePath/ls1327=== RUN TestIsValidCachePath/log1328=== PAUSE TestIsValidCachePath/log1329=== RUN TestIsValidCachePath/realisation1330=== PAUSE TestIsValidCachePath/realisation1331=== RUN TestIsValidCachePath/nix-cache-info1332=== PAUSE TestIsValidCachePath/nix-cache-info1333=== RUN TestIsValidCachePath/index.html1334=== PAUSE TestIsValidCachePath/index.html1335=== RUN TestIsValidCachePath/traversal_parent1336=== PAUSE TestIsValidCachePath/traversal_parent1337=== RUN TestIsValidCachePath/traversal_in_middle1338=== PAUSE TestIsValidCachePath/traversal_in_middle1339=== RUN TestIsValidCachePath/invalid_char_e1340=== PAUSE TestIsValidCachePath/invalid_char_e1341=== RUN TestIsValidCachePath/invalid_char_u1342=== PAUSE TestIsValidCachePath/invalid_char_u1343=== RUN TestIsValidCachePath/random_path1344=== PAUSE TestIsValidCachePath/random_path1345=== RUN TestIsValidCachePath/empty1346=== PAUSE TestIsValidCachePath/empty1347=== RUN TestIsValidCachePath/leading_slash1348=== PAUSE TestIsValidCachePath/leading_slash1349=== RUN TestIsValidCachePath/wrong_extension1350=== PAUSE TestIsValidCachePath/wrong_extension1351=== RUN TestIsValidCachePath/short_hash1352=== PAUSE TestIsValidCachePath/short_hash1353=== CONT TestPushDedupSurvivesConcurrentGC1354--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.78s)1355=== CONT TestProxyHeadersOnlyTrustedOnSocket13562026/10/01 13:03:46 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13572026/10/01 13:03:46 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1358--- PASS: TestService_NativeMTLS (2.19s)1359=== CONT TestPush_CompleteCommitsEveryRoot1360--- PASS: TestReadProxyInvalidPath (2.26s)1361=== CONT TestParseSingleRange1362=== RUN TestParseSingleRange/none1363=== PAUSE TestParseSingleRange/none1364=== RUN TestParseSingleRange/unknown_unit1365=== PAUSE TestParseSingleRange/unknown_unit1366=== RUN TestParseSingleRange/multi-range_ignored1367=== PAUSE TestParseSingleRange/multi-range_ignored1368=== RUN TestParseSingleRange/malformed_no_dash1369=== PAUSE TestParseSingleRange/malformed_no_dash1370=== RUN TestParseSingleRange/malformed_both_empty1371=== PAUSE TestParseSingleRange/malformed_both_empty1372=== RUN TestParseSingleRange/malformed_end_before_start1373=== PAUSE TestParseSingleRange/malformed_end_before_start1374=== RUN TestParseSingleRange/closed1375=== PAUSE TestParseSingleRange/closed1376=== RUN TestParseSingleRange/open-ended1377=== PAUSE TestParseSingleRange/open-ended1378=== RUN TestParseSingleRange/end_clamped_to_size1379=== PAUSE TestParseSingleRange/end_clamped_to_size1380=== RUN TestParseSingleRange/suffix1381=== PAUSE TestParseSingleRange/suffix1382=== RUN TestParseSingleRange/suffix_exceeds_size1383=== PAUSE TestParseSingleRange/suffix_exceeds_size1384=== RUN TestParseSingleRange/single_byte1385=== PAUSE TestParseSingleRange/single_byte1386=== RUN TestParseSingleRange/start_past_EOF1387=== PAUSE TestParseSingleRange/start_past_EOF1388=== RUN TestParseSingleRange/start_far_past_EOF1389=== PAUSE TestParseSingleRange/start_far_past_EOF1390=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1391--- PASS: TestReadProxy404 (2.40s)1392=== CONT TestPresentNotReportedWhileGCDeletesClosure1393--- PASS: TestReadProxyNarStreaming (2.33s)1394=== CONT TestGCTaskStore_Fail1395--- PASS: TestGCTaskStore_Fail (0.00s)1396=== CONT TestPresentReportsOnlyClosureRoots1397--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.14s)1398=== CONT TestMetricsInventory13992026/10/01 13:03:47 INFO Aborted multipart uploads count=0 kept=014002026/10/01 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period14012026/10/01 13:03:47 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=014022026/10/01 13:03:47 INFO Vacuumed table table=pending_closures14032026/10/01 13:03:47 INFO Vacuumed table table=pending_objects14042026/10/01 13:03:47 INFO Vacuumed table table=multipart_uploads14052026/10/01 13:03:47 INFO Vacuumed table table=closures14062026/10/01 13:03:47 INFO Vacuumed table table=objects14072026/10/01 13:03:47 INFO Aborted multipart uploads count=0 kept=014082026/10/01 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period14092026/10/01 13:03:47 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=014102026/10/01 13:03:47 INFO Vacuumed table table=pending_closures14112026/10/01 13:03:47 INFO Vacuumed table table=pending_objects14122026/10/01 13:03:47 INFO Vacuumed table table=multipart_uploads14132026/10/01 13:03:47 INFO Vacuumed table table=closures14142026/10/01 13:03:47 INFO Vacuumed table table=objects1415--- PASS: TestSweepSkipsRowsLockedByPush (2.41s)1416=== CONT TestCreatePin_ReservedPins14172026/10/01 13:03:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50739/oidc14182026/10/01 13:03:47 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"14192026/10/01 13:03:48 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161420--- PASS: TestReadProxyNarinfo (2.59s)1421=== CONT TestNARDeduplicationMetadataUploadBug14222026/10/01 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures14232026/10/01 13:03:48 INFO Aborted multipart uploads count=0 kept=014242026/10/01 13:03:48 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=014252026/10/01 13:03:48 INFO Vacuumed table table=pending_closures14262026/10/01 13:03:48 INFO Starting HTTP server address=/nix/var/nix/builds/nix-17449-2882215670/TestProxyHeadersOnlyTrustedOnSocket1732327302/001/proxy.sock14272026/10/01 13:03:48 INFO Starting HTTP server address=127.0.0.1:5074914282026/10/01 13:03:48 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14292026/10/01 13:03:48 INFO Vacuumed table table=pending_objects14302026/10/01 13:03:48 INFO Shutdown signal received, draining in-flight requests timeout=10s1431--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.47s)1432=== CONT TestOrphanedObjectsGCStressTest14332026/10/01 13:03:48 INFO Vacuumed table table=multipart_uploads14342026/10/01 13:03:48 INFO Vacuumed table table=closures14352026/10/01 13:03:48 INFO Vacuumed table table=objects14362026/10/01 13:03:48 INFO Aborted multipart uploads count=0 kept=014372026/10/01 13:03:48 WARN Force mode enabled - objects will be deleted immediately without grace period14382026/10/01 13:03:48 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=014392026/10/01 13:03:48 INFO Vacuumed table table=pending_closures14402026/10/01 13:03:48 INFO Vacuumed table table=pending_objects14412026/10/01 13:03:48 INFO Vacuumed table table=multipart_uploads14422026/10/01 13:03:48 INFO Vacuumed table table=closures14432026/10/01 13:03:48 INFO Vacuumed table table=objects1444--- PASS: TestPushDedupSurvivesConcurrentGC (2.65s)1445=== CONT TestCreatePendingClosureRejectsOversizedNAR14462026/10/01 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures1447--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1448=== CONT TestOrphanedObjectsGC14492026/10/01 13:03:48 INFO Received push request method=POST path=/api/pushes14502026/10/01 13:03:48 INFO Received complete push request method=POST path=/api/pushes/1/complete1451--- PASS: TestPush_CompleteCommitsEveryRoot (2.24s)1452=== CONT TestCacheConfigHandlerMaxNarSize1453--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1454=== CONT TestObjectStatsTrigger14552026/10/01 13:03:48 INFO Received push request method=POST path=/api/pushes14562026/10/01 13:03:48 INFO Received complete push request method=POST path=/api/pushes/1/complete14572026/10/01 13:03:48 INFO Received push request method=POST path=/api/pushes14582026/10/01 13:03:48 INFO Aborted multipart uploads count=0 kept=014592026/10/01 13:03:48 WARN Force mode enabled - objects will be deleted immediately without grace period14602026/10/01 13:03:48 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=014612026/10/01 13:03:48 INFO Vacuumed table table=pending_closures14622026/10/01 13:03:48 INFO Vacuumed table table=pending_objects14632026/10/01 13:03:48 INFO Vacuumed table table=multipart_uploads14642026/10/01 13:03:48 INFO Vacuumed table table=closures14652026/10/01 13:03:49 INFO Vacuumed table table=objects14662026/10/01 13:03:49 INFO Received complete push request method=POST path=/api/pushes/2/complete1467--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.37s)1468=== CONT TestGenerateLandingPage1469--- PASS: TestGenerateLandingPage (0.00s)1470=== CONT TestPendingCleanupUsesOneCutoff1471--- PASS: TestPresentReportsOnlyClosureRoots (2.05s)1472=== CONT TestService_readinessHandler1473--- PASS: TestMetricsInventory (2.09s)1474=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1475--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.51s)1476=== CONT TestService_healthCheckHandler14772026/10/01 13:03:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14782026/10/01 13:03:49 WARN Refused reserved pin name=worker-x86_64-linux14792026/10/01 13:03:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14802026/10/01 13:03:49 INFO Received create pin request method=POST path=/api/pins/my-app14812026/10/01 13:03:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1482--- PASS: TestCreatePin_ReservedPins (1.95s)1483=== CONT TestMultipartCleanup1484=== NAME TestNARDeduplicationMetadataUploadBug1485 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-17449-2882215670/TestNARDeduplicationMetadataUploadBug1227319009/001/store/cvz90m3yqplv9y3qq6ldnw1lmw9p1hsd-file1.txt14862026/10/01 13:03:50 INFO Received push request method=POST path=/api/pushes14872026/10/01 13:03:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14882026/10/01 13:03:50 INFO Uploading cvz90m3yqplv9y3qq6ldnw1lmw9p1hsd-file1.txt (160B)14892026/10/01 13:03:50 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14902026/10/01 13:03:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14912026/10/01 13:03:50 INFO Signed narinfos id=1 count=114922026/10/01 13:03:50 INFO Uploading 1 narinfos14932026/10/01 13:03:50 WARN Failed to register uploaded object key=cvz90m3yqplv9y3qq6ldnw1lmw9p1hsd.ls error="server returned 404: 404 page not found\n"14942026/10/01 13:03:50 INFO Received complete push request method=POST path=/api/pushes/1/complete14952026/10/01 13:03:50 WARN Failed to register uploaded object key=cvz90m3yqplv9y3qq6ldnw1lmw9p1hsd.narinfo error="server returned 404: 404 page not found\n"14962026/10/01 13:03:50 INFO Upload complete. (127ms)1497 metadata_upload_test.go:54: Retrieved narinfo from S3:1498 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestNARDeduplicationMetadataUploadBug1227319009/001/store/cvz90m3yqplv9y3qq6ldnw1lmw9p1hsd-file1.txt1499 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1500 Compression: zstd1501 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1502 NarSize: 1601503 References: 1504 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1505 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1506 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1507 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1508 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-17449-2882215670/TestNARDeduplicationMetadataUploadBug1227319009/001/store/k9fsl095csh4d61q4mald9iin9ra91kr-file2.txt15092026/10/01 13:03:50 INFO Received push request method=POST path=/api/pushes15102026/10/01 13:03:50 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15112026/10/01 13:03:50 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15122026/10/01 13:03:50 INFO Signed narinfos id=2 count=115132026/10/01 13:03:50 INFO Uploading 1 narinfos15142026/10/01 13:03:50 WARN Failed to register uploaded object key=k9fsl095csh4d61q4mald9iin9ra91kr.ls error="server returned 404: 404 page not found\n"15152026/10/01 13:03:50 INFO Received complete push request method=POST path=/api/pushes/2/complete15162026/10/01 13:03:50 WARN Failed to register uploaded object key=k9fsl095csh4d61q4mald9iin9ra91kr.narinfo error="server returned 404: 404 page not found\n"15172026/10/01 13:03:50 INFO Upload complete. (78ms)1518 metadata_upload_test.go:76: Retrieved narinfo from S3:1519 StorePath: /nix/var/nix/builds/nix-17449-2882215670/TestNARDeduplicationMetadataUploadBug1227319009/001/store/k9fsl095csh4d61q4mald9iin9ra91kr-file2.txt1520 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1521 Compression: zstd1522 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1523 NarSize: 1601524 References: 1525 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1526 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1527 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1528 {"version":1,"root":{"type":"regular","size":44}}1529--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.41s)1530=== CONT TestGracefulShutdownDrainsInflight15312026/10/01 13:03:50 INFO Starting HTTP server address=127.0.0.1:5079115322026/10/01 13:03:50 INFO Shutdown signal received, draining in-flight requests timeout=10s1533--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1534=== CONT TestServerTLSConfig1535=== RUN TestServerTLSConfig/no_client_CA1536=== PAUSE TestServerTLSConfig/no_client_CA1537=== RUN TestServerTLSConfig/missing_CA_file1538=== PAUSE TestServerTLSConfig/missing_CA_file1539=== RUN TestServerTLSConfig/not_a_PEM_file1540=== PAUSE TestServerTLSConfig/not_a_PEM_file1541=== CONT TestGCMetrics1542--- PASS: TestNARDeduplicationMetadataUploadBug (2.31s)1543=== CONT TestGCTaskStore_ConflictDifferentParams1544--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1545=== CONT TestGCTaskStore_CompletedAllowsNewTask1546--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1547=== CONT TestGCTaskStore_GetReturnsLatest1548--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1549=== CONT TestGCTaskStore_PhaseUpdates1550--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1551=== CONT TestGCTaskStore_GetEmpty1552--- PASS: TestGCTaskStore_GetEmpty (0.00s)1553=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1554--- PASS: TestObjectStatsTrigger (1.97s)1555=== CONT TestForceGCDuringPushOffersSweptObject1556=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1557=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1558=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1559=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1560=== CONT TestGCSweepDeliversEachKeyOnce1561=== NAME TestOrphanedObjectsGC1562 orphaned_objects_gc_test.go:290: GC Test Summary:1563 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1564 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1565 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1566 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1567 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1568--- PASS: TestOrphanedObjectsGC (2.28s)1569=== CONT TestGCTaskStore_StartNew1570--- PASS: TestGCTaskStore_StartNew (0.00s)1571=== CONT TestGCTaskStore_DeduplicateSameParams1572--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1573=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15742026/10/01 13:03:50 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/01 13:03:50 INFO Received uploads request method=POST path=/api/pending_closures15762026/10/01 13:03:50 INFO Received cleanup request method=DELETE path=/api/pending_closures15772026/10/01 13:03:51 WARN readiness check failed error="closed pool"1578--- PASS: TestService_readinessHandler (2.03s)1579=== CONT TestReadRedirectUsesPublicS3URL15802026/10/01 13:03:51 INFO Received uploads request method=POST path=/api/pending_closures1581--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.20s)1582=== CONT TestGCEndsOnShutdown1583--- PASS: TestService_healthCheckHandler (2.34s)1584=== CONT TestCommitRacingPendingCleanupKeepsObjects15852026/10/01 13:03:52 INFO Received uploads request method=POST path=/api/pending_closures15862026/10/01 13:03:52 INFO Received cleanup request method=DELETE path=/api/pending_closures15872026/10/01 13:03:52 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket75/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15882026/10/01 13:03:52 INFO Aborted multipart uploads count=0 kept=115892026/10/01 13:03:52 INFO Received cleanup request method=DELETE path=/api/pending_closures15902026/10/01 13:03:52 INFO Aborted multipart uploads count=1 kept=01591--- PASS: TestMultipartCleanup (2.73s)1592=== CONT TestClientErrorHandling/InvalidStorePath15932026/10/01 13:03:52 INFO Aborted multipart uploads count=0 kept=015942026/10/01 13:03:52 WARN Force mode enabled - objects will be deleted immediately without grace period15952026/10/01 13:03:52 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=015962026/10/01 13:03:52 INFO Vacuumed table table=pending_closures15972026/10/01 13:03:52 INFO Vacuumed table table=pending_objects15982026/10/01 13:03:52 INFO Vacuumed table table=multipart_uploads15992026/10/01 13:03:52 INFO Vacuumed table table=closures16002026/10/01 13:03:52 INFO Vacuumed table table=objects1601--- PASS: TestGCMetrics (2.43s)1602=== CONT TestClientErrorHandling/ServerNotAvailable16032026/10/01 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures16042026/10/01 13:03:53 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/present16052026/10/01 13:03:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.878286ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1606--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.88s)1607=== CONT TestClientErrorHandling/InvalidAuthToken16082026/10/01 13:03:53 INFO Aborted multipart uploads count=0 kept=016092026/10/01 13:03:53 WARN Force mode enabled - objects will be deleted immediately without grace period16102026/10/01 13:03:53 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=016112026/10/01 13:03:53 INFO Vacuumed table table=pending_closures16122026/10/01 13:03:53 INFO Vacuumed table table=pending_objects16132026/10/01 13:03:53 INFO Vacuumed table table=multipart_uploads16142026/10/01 13:03:53 INFO Vacuumed table table=closures16152026/10/01 13:03:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.134889ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16162026/10/01 13:03:53 INFO Vacuumed table table=objects1617--- PASS: TestGCSweepDeliversEachKeyOnce (2.87s)1618=== CONT TestPush_RejectsBadRequests16192026/10/01 13:03:53 INFO Received push request method=POST path=/api/pushes1620--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.97s)1621=== CONT TestResolveDBConnectionString/flag_wins1622=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1623=== CONT TestResolveDBConnectionString/nothing_configured1624=== CONT TestResolveDBConnectionString/missing_file_is_an_error1625=== CONT TestResolveDBConnectionString/file_when_flag_empty1626=== CONT TestCacheConfigHandler/full_config,_no_issuer1627=== CONT TestCacheConfigHandler/no_signing_keys1628=== CONT TestCacheConfigHandler/no_cache_url_configured1629=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1630--- PASS: TestCacheConfigHandler (0.00s)1631 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1632 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1633 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1634 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1635=== CONT TestService_RequireScope_OIDC/builder_may_write1636=== CONT TestService_RequireScope_OIDC/static_token_may_admin1637=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1638=== CONT TestService_RequireScope_OIDC/writer_implies_read1639=== CONT TestService_RequireScope_OIDC/reader_may_read1640=== CONT TestService_RequireScope_OIDC/static_token_may_write1641=== CONT TestService_RequireScope_OIDC/ops_may_not_write1642=== CONT TestService_RequireScope_OIDC/reader_may_not_write1643=== CONT TestService_RequireScope_OIDC/ops_may_admin1644=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1645=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1646=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16472026/10/01 13:03:53 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]1648=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1649=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1650--- PASS: TestService_RequireScope_OIDC (1.41s)1651 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1652 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1653 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1654 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1655 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1656 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1657 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1658 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1659 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1660 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1661--- PASS: TestResolveDBConnectionString (0.01s)1662 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1663 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1664 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1665 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1666 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16672026/10/01 13:03:53 WARN Authentication failed token_preview=eyJhbGciOi...gEdM7KwByA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1668=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16692026/10/01 13:03:53 INFO Received uploads request method=POST path=/1670--- PASS: TestService_AuthMiddleware_OIDC (1.36s)1671 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1672 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1673 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1674 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16752026/10/01 13:03:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=825.923178ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1676--- PASS: TestReadRedirectUsesPublicS3URL (2.65s)1677=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16782026/10/01 13:03:53 INFO Received request for more parts method=POST path=/1679=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16802026/10/01 13:03:53 INFO Received complete multipart upload request method=POST path=/1681=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16822026/10/01 13:03:53 INFO Received uploads request method=POST path=/1683=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16842026/10/01 13:03:53 INFO Received complete multipart upload request method=POST path=/1685=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16862026/10/01 13:03:53 INFO Received request for more parts method=POST path=/1687=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16882026/10/01 13:03:53 INFO Received uploads request method=POST path=/1689--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1690 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1691 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1692 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1693 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1694=== CONT TestIsValidUploadKey/narinfo1695=== CONT TestIsValidUploadKey/realisation_plus_in_output1696=== CONT TestIsValidUploadKey/unknown_type1697=== CONT TestIsValidUploadKey/empty_key1698=== CONT TestIsValidUploadKey/absolute1699=== CONT TestIsValidUploadKey/traversal_nar1700=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1701=== CONT TestIsValidUploadKey/index.html1702=== CONT TestIsValidUploadKey/nix-cache-info1703=== CONT TestIsValidUploadKey/build_log_home-manager_file1704=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1705=== CONT TestIsValidUploadKey/realisation1706=== CONT TestIsValidUploadKey/traversal1707=== CONT TestIsValidUploadKey/build_log_equals1708=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1709=== CONT TestIsValidUploadKey/build_log_question_mark1710=== CONT TestIsValidUploadKey/nar_plain1711=== CONT TestIsValidUploadKey/build_log1712=== CONT TestIsValidUploadKey/listing1713=== CONT TestIsValidUploadKey/build_log_plus_in_name1714=== CONT TestIsValidUploadKey/nar_xz1715=== CONT TestIsValidUploadKey/nar_zst1716--- PASS: TestIsValidUploadKey (0.00s)1717 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1719 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1720 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1721 --- PASS: TestIsValidUploadKey/absolute (0.00s)1722 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1723 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1724 --- PASS: TestIsValidUploadKey/index.html (0.00s)1725 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1726 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1728 --- PASS: TestIsValidUploadKey/realisation (0.00s)1729 --- PASS: TestIsValidUploadKey/traversal (0.00s)1730 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1731 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1733 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1734 --- PASS: TestIsValidUploadKey/build_log (0.00s)1735 --- PASS: TestIsValidUploadKey/listing (0.00s)1736 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1737 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1738 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1739=== CONT TestPendingClosureWriteTimeout/empty1740=== CONT TestPendingClosureWriteTimeout/670k_objects1741=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1742--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1743 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1744 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1745 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1746=== CONT TestPendingClosureWriteTimeout/400_objects1747=== CONT TestProxyWriteTimeout/narinfo1748=== CONT TestProxyWriteTimeout/10_GiB_nar1749=== CONT TestProxyWriteTimeout/unknown_size1750=== CONT TestProxyWriteTimeout/1_GiB_nar1751--- PASS: TestProxyWriteTimeout (0.00s)1752 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1753 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1754 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1755 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1756=== CONT TestIsValidCachePath/narinfo1757=== CONT TestIsValidCachePath/index.html1758=== CONT TestIsValidCachePath/short_hash1759=== CONT TestIsValidCachePath/wrong_extension1760=== CONT TestIsValidCachePath/leading_slash1761=== CONT TestIsValidCachePath/empty1762=== CONT TestIsValidCachePath/random_path1763=== CONT TestIsValidCachePath/invalid_char_u1764=== CONT TestIsValidCachePath/invalid_char_e1765=== CONT TestIsValidCachePath/traversal_in_middle1766=== CONT TestIsValidCachePath/traversal_parent1767=== CONT TestIsValidCachePath/nar_uncompressed1768=== CONT TestIsValidCachePath/nix-cache-info1769=== CONT TestIsValidCachePath/realisation1770=== CONT TestIsValidCachePath/log1771=== CONT TestIsValidCachePath/ls1772=== CONT TestIsValidCachePath/nar_xz1773=== CONT TestIsValidCachePath/nar_bz21774=== CONT TestIsValidCachePath/nar_zst1775=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1776--- PASS: TestIsValidCachePath (0.00s)1777 --- PASS: TestIsValidCachePath/narinfo (0.00s)1778 --- PASS: TestIsValidCachePath/index.html (0.00s)1779 --- PASS: TestIsValidCachePath/short_hash (0.00s)1780 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1781 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1782 --- PASS: TestIsValidCachePath/realisation (0.00s)1783 --- PASS: TestIsValidCachePath/log (0.00s)1784 --- PASS: TestIsValidCachePath/ls (0.00s)1785 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1786 --- PASS: TestIsValidCachePath/nar_bz2 (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/nar_zst (0.00s)1796 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1797=== CONT TestParseSingleRange/none1798=== CONT TestParseSingleRange/open-ended1799=== CONT TestParseSingleRange/start_far_past_EOF1800=== CONT TestParseSingleRange/start_past_EOF1801=== CONT TestParseSingleRange/single_byte1802=== CONT TestParseSingleRange/suffix_exceeds_size1803=== CONT TestParseSingleRange/suffix1804=== CONT TestParseSingleRange/end_clamped_to_size1805=== CONT TestParseSingleRange/malformed_both_empty1806=== CONT TestParseSingleRange/closed1807=== CONT TestParseSingleRange/malformed_end_before_start1808=== CONT TestParseSingleRange/multi-range_ignored1809=== CONT TestParseSingleRange/malformed_no_dash1810=== CONT TestParseSingleRange/unknown_unit1811--- PASS: TestParseSingleRange (0.00s)1812 --- PASS: TestParseSingleRange/none (0.00s)1813 --- PASS: TestParseSingleRange/open-ended (0.00s)1814 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1815 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1816 --- PASS: TestParseSingleRange/single_byte (0.00s)1817 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1818 --- PASS: TestParseSingleRange/suffix (0.00s)1819 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1820 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1821 --- PASS: TestParseSingleRange/closed (0.00s)1822 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1823 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1824 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1825 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1826=== CONT TestServerTLSConfig/no_client_CA1827=== CONT TestServerTLSConfig/not_a_PEM_file1828=== CONT TestServerTLSConfig/missing_CA_file1829--- PASS: TestServerTLSConfig (0.00s)1830 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1831 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)1832 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1833=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1834--- PASS: TestGCEndsOnShutdown (2.59s)1835=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18362026/10/01 13:03:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.652021864s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18372026/10/01 13:03:54 INFO Aborted multipart uploads count=0 kept=018382026/10/01 13:03:54 WARN Force mode enabled - objects will be deleted immediately without grace period18392026/10/01 13:03:54 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=018402026/10/01 13:03:54 INFO Vacuumed table table=pending_closures18412026/10/01 13:03:54 INFO Vacuumed table table=pending_objects18422026/10/01 13:03:54 INFO Vacuumed table table=multipart_uploads18432026/10/01 13:03:54 INFO Vacuumed table table=closures18442026/10/01 13:03:54 INFO Vacuumed table table=objects1845--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.92s)1846=== NAME TestOrphanedObjectsGCStressTest1847 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1848 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18492026/10/01 13:03:56 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-config1850=== RUN TestPush_RejectsBadRequests/no_roots1851=== PAUSE TestPush_RejectsBadRequests/no_roots1852=== RUN TestPush_RejectsBadRequests/no_objects1853=== PAUSE TestPush_RejectsBadRequests/no_objects1854=== RUN TestPush_RejectsBadRequests/bad_root1855=== PAUSE TestPush_RejectsBadRequests/bad_root1856=== RUN TestPush_RejectsBadRequests/root_not_in_objects1857=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1858=== CONT TestPush_RejectsBadRequests/no_roots1859=== CONT TestPush_RejectsBadRequests/bad_root1860=== CONT TestPush_RejectsBadRequests/root_not_in_objects18612026/10/01 13:03:56 INFO Received push request method=POST path=/api/pushes18622026/10/01 13:03:56 INFO Received push request method=POST path=/api/pushes1863=== CONT TestPush_RejectsBadRequests/no_objects18642026/10/01 13:03:56 INFO Received push request method=POST path=/api/pushes18652026/10/01 13:03:56 INFO Received push request method=POST path=/api/pushes1866--- PASS: TestPush_RejectsBadRequests (2.99s)1867 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1868 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1869 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1870 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)18712026/10/01 13:03:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18722026/10/01 13:03:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.480415ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18732026/10/01 13:03:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18742026/10/01 13:03:56 INFO Received uploads request method=POST path=/api/pending_closures18752026/10/01 13:03:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.706751ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18762026/10/01 13:03:56 INFO Received uploads request method=POST path=/api/pending_closures18772026/10/01 13:03:56 INFO Aborted multipart uploads count=0 kept=018782026/10/01 13:03:56 INFO Aborted multipart uploads count=1 kept=018792026/10/01 13:03:56 WARN Force mode enabled - objects will be deleted immediately without grace period18802026/10/01 13:03:56 INFO Received cleanup request method=DELETE path=/api/pending_closures18812026/10/01 13:03:56 INFO Aborted multipart uploads count=1 kept=01882--- PASS: TestPendingCleanupUsesOneCutoff (7.96s)18832026/10/01 13:03:56 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=018842026/10/01 13:03:56 INFO Vacuumed table table=pending_closures18852026/10/01 13:03:56 INFO Vacuumed table table=pending_objects18862026/10/01 13:03:56 INFO Vacuumed table table=multipart_uploads18872026/10/01 13:03:56 INFO Vacuumed table table=closures18882026/10/01 13:03:57 INFO Vacuumed table table=objects18892026/10/01 13:03:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=783.977574ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18902026/10/01 13:03:57 INFO Received uploads request method=POST path=/api/pending_closures18912026/10/01 13:03:57 INFO Aborted multipart uploads count=0 kept=018922026/10/01 13:03:57 WARN Force mode enabled - objects will be deleted immediately without grace period18932026/10/01 13:03:57 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018942026/10/01 13:03:57 INFO Vacuumed table table=pending_closures18952026/10/01 13:03:57 INFO Vacuumed table table=pending_objects18962026/10/01 13:03:57 INFO Vacuumed table table=multipart_uploads18972026/10/01 13:03:57 INFO Vacuumed table table=closures18982026/10/01 13:03:57 INFO Vacuumed table table=objects1899--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1900 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.11s)1901 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.07s)1902--- PASS: TestPendingClosureWriteTimeout (0.00s)1903 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1904 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1905 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1906 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.57s)1907=== NAME TestOrphanedObjectsGCStressTest1908 orphaned_objects_gc_test.go:509: Stress test completed successfully:1909 orphaned_objects_gc_test.go:510: - Active objects preserved: 201910 orphaned_objects_gc_test.go:511: - Objects deleted: 2101911 orphaned_objects_gc_test.go:512: - Total GC'd: 2101912--- PASS: TestOrphanedObjectsGCStressTest (9.34s)19132026/10/01 13:03:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.539429789s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19142026/10/01 13:03:59 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"19152026/10/01 13:03:59 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-config19162026/10/01 13:03:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.697556ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19172026/10/01 13:03:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.713054ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19182026/10/01 13:04:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=837.423926ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19192026/10/01 13:04:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.689461183s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19202026/10/01 13:04:02 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_closures19212026/10/01 13:04:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.814715ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19222026/10/01 13:04:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.546601ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19232026/10/01 13:04:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=724.826177ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19242026/10/01 13:04:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.663219966s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1925--- PASS: TestClientErrorHandling (0.00s)1926 --- PASS: TestClientErrorHandling/InvalidStorePath (2.82s)1927 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.23s)1928 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.97s)1929PASS19302026-10-01 13:04:05.972 UTC [17486] LOG: received smart shutdown request19312026-10-01 13:04:05.973 UTC [17486] LOG: background worker "logical replication launcher" (PID 17496) exited with exit code 119322026-10-01 13:04:05.980 UTC [17491] LOG: shutting down19332026-10-01 13:04:05.980 UTC [17491] LOG: checkpoint starting: shutdown immediate19342026-10-01 13:04:07.220 UTC [17491] LOG: checkpoint complete: wrote 12773 buffers (78.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.700 s, sync=0.509 s, total=1.240 s; sync files=29992, longest=0.001 s, average=0.001 s; distance=421684 kB, estimate=421684 kB; lsn=0/1B35A208, redo lsn=0/1B35A20819352026-10-01 13:04:07.225 UTC [17486] LOG: database system is shut down1936Running OIDC tests...1937=== RUN TestAudienceForIssuer1938=== PAUSE TestAudienceForIssuer1939=== RUN TestGlobMatch1940=== PAUSE TestGlobMatch1941=== RUN TestValidateToken_ValidToken1942=== PAUSE TestValidateToken_ValidToken1943=== RUN TestValidateToken_WrongAudience1944=== PAUSE TestValidateToken_WrongAudience1945=== RUN TestValidateToken_Expired1946=== PAUSE TestValidateToken_Expired1947=== RUN TestValidateToken_BoundClaimsMismatch1948=== PAUSE TestValidateToken_BoundClaimsMismatch1949=== RUN TestValidateToken_BoundSubjectMismatch1950=== PAUSE TestValidateToken_BoundSubjectMismatch1951=== RUN TestValidateToken_MultipleProviders1952=== PAUSE TestValidateToken_MultipleProviders1953=== RUN TestValidateToken_NoMatchingProvider1954=== PAUSE TestValidateToken_NoMatchingProvider1955=== RUN TestValidateToken_KubernetesServiceAccount1956=== PAUSE TestValidateToken_KubernetesServiceAccount1957=== RUN TestNewValidator_KubernetesRequiresCA1958=== PAUSE TestNewValidator_KubernetesRequiresCA1959=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1960=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1961=== RUN TestPins_ReservedForMatchingRule1962=== PAUSE TestPins_ReservedForMatchingRule1963=== RUN TestPins_TopLevelShorthand1964=== PAUSE TestPins_TopLevelShorthand1965=== RUN TestPins_ConfigValidation1966=== PAUSE TestPins_ConfigValidation1967=== RUN TestScopes_LegacyProviderDefaultsToWrite1968=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1969=== RUN TestScopes_Rules1970=== PAUSE TestScopes_Rules1971=== RUN TestScopes_ConfigValidation1972=== PAUSE TestScopes_ConfigValidation1973=== CONT TestAudienceForIssuer1974=== CONT TestValidateToken_KubernetesServiceAccount1975=== CONT TestValidateToken_NoMatchingProvider1976=== CONT TestValidateToken_Expired1977=== CONT TestPins_ConfigValidation1978=== CONT TestValidateToken_ValidToken1979=== CONT TestValidateToken_WrongAudience1980=== CONT TestScopes_Rules1981=== CONT TestScopes_LegacyProviderDefaultsToWrite1982=== CONT TestScopes_ConfigValidation1983=== CONT TestPins_ReservedForMatchingRule1984=== CONT TestPins_TopLevelShorthand1985=== CONT TestValidateToken_BoundSubjectMismatch1986--- PASS: TestAudienceForIssuer (0.00s)1987--- PASS: TestPins_ConfigValidation (0.01s)1988--- PASS: TestScopes_ConfigValidation (0.00s)19892026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50899/oidc19902026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50901/oidc1991--- PASS: TestPins_TopLevelShorthand (0.04s)1992=== CONT TestValidateToken_KubernetesIssuerFromOwnToken1993--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)1994=== CONT TestNewValidator_KubernetesRequiresCA19952026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50903/oidc1996--- PASS: TestValidateToken_WrongAudience (0.07s)1997=== CONT TestValidateToken_BoundClaimsMismatch19982026/10/01 13:04:08 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1231999--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)2000=== CONT TestGlobMatch2001=== RUN TestGlobMatch/foo_foo2002=== PAUSE TestGlobMatch/foo_foo2003=== RUN TestGlobMatch/foo_bar2004=== PAUSE TestGlobMatch/foo_bar2005=== RUN TestGlobMatch/*_2006=== PAUSE TestGlobMatch/*_2007=== RUN TestGlobMatch/*_anything2008=== PAUSE TestGlobMatch/*_anything2009=== RUN TestGlobMatch/foo*_foo2010=== PAUSE TestGlobMatch/foo*_foo2011=== RUN TestGlobMatch/foo*_foobar2012=== PAUSE TestGlobMatch/foo*_foobar2013=== RUN TestGlobMatch/foo*_bar2014=== PAUSE TestGlobMatch/foo*_bar2015=== RUN TestGlobMatch/*bar_bar2016=== PAUSE TestGlobMatch/*bar_bar2017=== RUN TestGlobMatch/*bar_foobar2018=== PAUSE TestGlobMatch/*bar_foobar2019=== RUN TestGlobMatch/*bar_foo2020=== PAUSE TestGlobMatch/*bar_foo2021=== RUN TestGlobMatch/foo*bar_foobar2022=== PAUSE TestGlobMatch/foo*bar_foobar2023=== RUN TestGlobMatch/foo*bar_foo123bar2024=== PAUSE TestGlobMatch/foo*bar_foo123bar2025=== RUN TestGlobMatch/foo*bar_foobarbaz2026=== PAUSE TestGlobMatch/foo*bar_foobarbaz2027=== RUN TestGlobMatch/*/*_foo/bar2028=== PAUSE TestGlobMatch/*/*_foo/bar2029=== RUN TestGlobMatch/*/*_foo2030=== PAUSE TestGlobMatch/*/*_foo2031=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2032=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2033=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02034=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02035=== RUN TestGlobMatch/refs/*/main_refs/heads/main2036=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2037=== RUN TestGlobMatch/fo?_foo2038=== PAUSE TestGlobMatch/fo?_foo2039=== RUN TestGlobMatch/fo?_fo2040=== PAUSE TestGlobMatch/fo?_fo2041=== RUN TestGlobMatch/fo?_fooo2042=== PAUSE TestGlobMatch/fo?_fooo2043=== RUN TestGlobMatch/?oo_foo2044=== PAUSE TestGlobMatch/?oo_foo2045=== RUN TestGlobMatch/?oo_boo2046=== PAUSE TestGlobMatch/?oo_boo2047=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2048=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2049=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2050=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2051=== CONT TestValidateToken_MultipleProviders20522026/10/01 13:04:08 http: TLS handshake error from 127.0.0.1:50908: read tcp 127.0.0.1:50907->127.0.0.1:50908: use of closed network connection2053--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2054=== CONT TestGlobMatch/foo_foo2055=== CONT TestGlobMatch/*/*_foo/bar2056=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2057=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2058=== CONT TestGlobMatch/?oo_boo2059=== CONT TestGlobMatch/?oo_foo2060=== CONT TestGlobMatch/fo?_fooo2061=== CONT TestGlobMatch/fo?_fo2062=== CONT TestGlobMatch/fo?_foo2063=== CONT TestGlobMatch/refs/*/main_refs/heads/main2064=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02065=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2066=== CONT TestGlobMatch/*/*_foo2067=== CONT TestGlobMatch/foo*bar_foobarbaz2068=== CONT TestGlobMatch/foo*bar_foo123bar2069=== CONT TestGlobMatch/foo*bar_foobar2070=== CONT TestGlobMatch/*bar_foo2071=== CONT TestGlobMatch/*bar_foobar2072=== CONT TestGlobMatch/*bar_bar2073=== CONT TestGlobMatch/foo*_bar2074=== CONT TestGlobMatch/foo*_foobar2075=== CONT TestGlobMatch/foo*_foo2076=== CONT TestGlobMatch/*_anything2077=== CONT TestGlobMatch/*_2078=== CONT TestGlobMatch/foo_bar2079--- PASS: TestGlobMatch (0.00s)2080 --- PASS: TestGlobMatch/foo_foo (0.00s)2081 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2082 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2083 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2084 --- PASS: TestGlobMatch/?oo_boo (0.00s)2085 --- PASS: TestGlobMatch/?oo_foo (0.00s)2086 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2087 --- PASS: TestGlobMatch/fo?_fo (0.00s)2088 --- PASS: TestGlobMatch/fo?_foo (0.00s)2089 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2090 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2091 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2092 --- PASS: TestGlobMatch/*/*_foo (0.00s)2093 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2094 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2095 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2096 --- PASS: TestGlobMatch/*bar_foo (0.00s)2097 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2098 --- PASS: TestGlobMatch/*bar_bar (0.00s)2099 --- PASS: TestGlobMatch/foo*_bar (0.00s)2100 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2101 --- PASS: TestGlobMatch/foo*_foo (0.00s)2102 --- PASS: TestGlobMatch/*_anything (0.00s)2103 --- PASS: TestGlobMatch/*_ (0.00s)2104 --- PASS: TestGlobMatch/foo_bar (0.00s)21052026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50909/oidc21062026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50912/oidc2107--- PASS: TestScopes_Rules (0.11s)2108--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)21092026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50915/oidc2110--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)21112026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50917/oidc2112--- PASS: TestValidateToken_Expired (0.13s)21132026/10/01 13:04:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50914/oidc2114--- PASS: TestValidateToken_NoMatchingProvider (0.14s)21152026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50921/oidc2116--- PASS: TestPins_ReservedForMatchingRule (0.13s)21172026/10/01 13:04:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50923/oidc2118--- PASS: TestValidateToken_ValidToken (0.14s)21192026/10/01 13:04:08 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:509252120--- PASS: TestValidateToken_KubernetesServiceAccount (0.18s)21212026/10/01 13:04:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50910/oidc21222026/10/01 13:04:08 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50927/oidc2123--- PASS: TestValidateToken_MultipleProviders (0.10s)2124PASS2125Running hook tests...2126=== RUN TestSendPathsEmpty2127=== PAUSE TestSendPathsEmpty2128=== RUN TestQueueEnqueueAndFetch2129=== PAUSE TestQueueEnqueueAndFetch2130=== RUN TestQueueDeduplication2131=== PAUSE TestQueueDeduplication2132=== RUN TestQueueRemove2133=== PAUSE TestQueueRemove2134=== RUN TestQueueFetchBatchLimit2135=== PAUSE TestQueueFetchBatchLimit2136=== RUN TestQueueRetryMovesToBack2137=== PAUSE TestQueueRetryMovesToBack2138=== RUN TestQueueFetchRemoveLifecycle2139=== PAUSE TestQueueFetchRemoveLifecycle2140=== RUN TestQueueConcurrentWriters2141=== PAUSE TestQueueConcurrentWriters2142=== RUN TestQueueRemoveLargeClosure2143=== PAUSE TestQueueRemoveLargeClosure2144=== RUN TestServerClientIntegration2145=== PAUSE TestServerClientIntegration2146=== RUN TestServerQueueError2147=== PAUSE TestServerQueueError2148=== RUN TestGetListenerSocketActivation2149 server_test.go:210: === RUN TestGetListenerSocketActivation2150 --- PASS: TestGetListenerSocketActivation (0.00s)2151 PASS2152 2153--- PASS: TestGetListenerSocketActivation (0.01s)2154=== RUN TestDrainIsolatesPoisonPath2155=== PAUSE TestDrainIsolatesPoisonPath2156=== RUN TestRunNotBlockedByPoisonHead2157=== PAUSE TestRunNotBlockedByPoisonHead2158=== RUN TestDrainGivesUpWhenServerDown2159=== PAUSE TestDrainGivesUpWhenServerDown2160=== RUN TestFailedPathPrunedByLaterClosure2161=== PAUSE TestFailedPathPrunedByLaterClosure2162=== RUN TestWorkerUploadsAndRemoves2163=== PAUSE TestWorkerUploadsAndRemoves2164=== RUN TestWorkerSkipsGCdPaths2165=== PAUSE TestWorkerSkipsGCdPaths2166=== RUN TestWorkerPrunesClosureDeps2167=== PAUSE TestWorkerPrunesClosureDeps2168=== RUN TestDrainTimeout2169=== PAUSE TestDrainTimeout2170=== CONT TestSendPathsEmpty2171=== CONT TestServerQueueError2172--- PASS: TestSendPathsEmpty (0.00s)2173=== CONT TestServerClientIntegration2174=== CONT TestWorkerUploadsAndRemoves2175=== CONT TestQueueRetryMovesToBack2176=== CONT TestWorkerPrunesClosureDeps2177=== CONT TestWorkerSkipsGCdPaths2178=== CONT TestDrainGivesUpWhenServerDown2179=== CONT TestRunNotBlockedByPoisonHead2180=== CONT TestDrainTimeout2181=== CONT TestDrainIsolatesPoisonPath21822026/10/01 13:04:08 ERROR Failed to queue paths error="permission denied" count=12183--- PASS: TestServerClientIntegration (0.00s)2184=== CONT TestFailedPathPrunedByLaterClosure2185--- PASS: TestServerQueueError (0.00s)2186=== CONT TestQueueFetchBatchLimit21872026/10/01 13:04:08 INFO Upload queue status pending=321882026/10/01 13:04:08 INFO Uploading batch count=121892026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=121902026/10/01 13:04:08 INFO Uploading batch count=22191--- PASS: TestQueueFetchBatchLimit (0.01s)21922026/10/01 13:04:08 INFO Uploading batch count=121932026/10/01 13:04:08 INFO Upload queue status pending=221942026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=121952026/10/01 13:04:08 INFO Uploading batch count=22196=== CONT TestQueueRemove21972026/10/01 13:04:08 INFO Upload queue status pending=221982026/10/01 13:04:08 INFO Upload queue status pending=221992026/10/01 13:04:08 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-17449-2882215670/TestWorkerSkipsGCdPaths1870289432/002/nonexistent22002026/10/01 13:04:08 INFO Uploading batch count=122012026/10/01 13:04:08 INFO Uploading batch count=122022026/10/01 13:04:08 INFO Uploading batch count=422032026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=422042026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainIsolatesPoisonPath2221631847/002/bbb22052026/10/01 13:04:08 INFO Uploading batch count=122062026/10/01 13:04:08 INFO Uploading batch count=222072026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=222082026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/a2209--- PASS: TestQueueRetryMovesToBack (0.01s)2210=== CONT TestQueueDeduplication22112026/10/01 13:04:08 INFO Uploading batch count=122122026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/b22132026/10/01 13:04:08 INFO Uploading batch count=222142026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=222152026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/c22162026/10/01 13:04:08 INFO Uploading batch count=122172026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=122182026/10/01 13:04:08 INFO Uploading batch count=122192026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=122202026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/d22212026/10/01 13:04:08 INFO Uploading batch count=122222026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=122232026/10/01 13:04:08 ERROR Drain finished with paths left in queue remaining=122242026/10/01 13:04:08 INFO Uploading batch count=222252026/10/01 13:04:08 ERROR Upload failed error="upload failed" count=222262026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/e2227--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2228=== CONT TestQueueEnqueueAndFetch22292026/10/01 13:04:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-17449-2882215670/TestDrainGivesUpWhenServerDown614021910/002/f22302026/10/01 13:04:08 ERROR Drain finished with paths left in queue remaining=102231--- PASS: TestDrainIsolatesPoisonPath (0.01s)2232=== CONT TestQueueRemoveLargeClosure2233--- PASS: TestQueueRemove (0.00s)2234=== CONT TestQueueConcurrentWriters2235--- PASS: TestQueueDeduplication (0.00s)2236=== CONT TestQueueFetchRemoveLifecycle2237--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2238--- PASS: TestQueueEnqueueAndFetch (0.00s)2239--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2240--- PASS: TestWorkerSkipsGCdPaths (0.03s)2241--- PASS: TestWorkerUploadsAndRemoves (0.03s)2242--- PASS: TestWorkerPrunesClosureDeps (0.03s)2243--- PASS: TestQueueRemoveLargeClosure (0.04s)2244--- PASS: TestQueueConcurrentWriters (0.15s)22452026/10/01 13:04:09 ERROR Upload failed error="context deadline exceeded" count=222462026/10/01 13:04:09 ERROR Drain finished with paths left in queue remaining=42247--- PASS: TestDrainTimeout (0.21s)22482026/10/01 13:04:09 INFO Uploading batch count=122492026/10/01 13:04:09 INFO Uploading batch count=122502026/10/01 13:04:09 INFO Uploading batch count=122512026/10/01 13:04:09 ERROR Upload failed error="upload failed" count=122522026/10/01 13:04:09 INFO Uploading batch count=122532026/10/01 13:04:09 ERROR Upload failed error="upload failed" count=122542026/10/01 13:04:09 INFO Uploading batch count=122552026/10/01 13:04:09 ERROR Upload failed error="upload failed" count=122562026/10/01 13:04:09 INFO Uploading batch count=122572026/10/01 13:04:09 ERROR Upload failed error="upload failed" count=122582026/10/01 13:04:09 ERROR Drain finished with paths left in queue remaining=12259--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2260PASS