niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #346
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97--- PASS: TestShellSplit (0.00s)98--- PASS: TestEncodeNixBase32WithRealHash (0.00s)99=== CONT TestFileTokenEmpty100=== CONT TestScriptTokenEmptyCommand101--- PASS: TestScriptTokenEmptyCommand (0.00s)102=== CONT TestFileTokenReadsAndCaches103=== CONT TestScriptTokenScriptFails104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108--- PASS: TestFileTokenEmpty (0.00s)109=== CONT TestStaticToken110=== CONT TestSetClientTLSErrors111=== CONT TestFileTokenMissing112--- PASS: TestStaticToken (0.00s)113=== CONT TestUploadMultipart_SupersededByPeer114=== RUN TestUploadMultipart_SupersededByPeer/exists115=== PAUSE TestUploadMultipart_SupersededByPeer/exists116=== RUN TestUploadMultipart_SupersededByPeer/missing117=== PAUSE TestUploadMultipart_SupersededByPeer/missing118=== CONT TestEncodeNixBase32119=== RUN TestEncodeNixBase32/test_string_hash120=== PAUSE TestEncodeNixBase32/test_string_hash121=== RUN TestEncodeNixBase32/empty_input122--- PASS: TestFileTokenReadsAndCaches (0.00s)123=== PAUSE TestEncodeNixBase32/empty_input124=== CONT TestDumpPathWriterError125=== CONT TestDumpPathSingleFile126--- PASS: TestFileTokenMissing (0.00s)127=== CONT TestDumpPathMatchesNix128--- PASS: TestDoServerRequestAttachesToken (0.01s)129=== CONT TestFilterOversizedClosures130--- PASS: TestScriptTokenScriptFails (0.01s)131=== CONT TestPartSizeForNAR132=== RUN TestPartSizeForNAR/zero_stays_at_minimum133=== RUN TestFilterOversizedClosures/no_limit_keeps_everything134=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum135=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything136=== RUN TestSetClientTLSErrors/missing_cert_file137=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped138=== PAUSE TestSetClientTLSErrors/missing_cert_file139=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped140=== RUN TestPartSizeForNAR/small_stays_at_minimum141=== PAUSE TestPartSizeForNAR/small_stays_at_minimum142=== RUN TestFilterOversizedClosures/all_closures_skipped143=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum144=== RUN TestSetClientTLSErrors/missing_key_file145=== PAUSE TestFilterOversizedClosures/all_closures_skipped146=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum147=== PAUSE TestSetClientTLSErrors/missing_key_file148=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts149=== RUN TestSetClientTLSErrors/missing_ca_file150=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts151=== RUN TestPartSizeForNAR/1_TiB152=== CONT TestUploadMultipart_PartsInParallel153=== PAUSE TestSetClientTLSErrors/missing_ca_file154=== RUN TestSetClientTLSErrors/invalid_ca_file155=== PAUSE TestSetClientTLSErrors/invalid_ca_file156=== PAUSE TestPartSizeForNAR/1_TiB157=== CONT TestRegisterUploadedObjectReusesConnections158=== RUN TestPartSizeForNAR/5_TiB_S3_max_object159=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object160=== RUN TestPartSizeForNAR/capped_at_5_GiB161=== PAUSE TestPartSizeForNAR/capped_at_5_GiB162=== CONT TestPathInfoCACompatibility163=== RUN TestPathInfoCACompatibility/null_ca_field164=== PAUSE TestPathInfoCACompatibility/null_ca_field165=== RUN TestPathInfoCACompatibility/old_string_format_-_text166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestPathInfoCACompatibility/new_structured_format_-_text170=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text171=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method172--- PASS: TestScriptTokenEmptyToken (0.01s)173=== CONT TestDoWithRetry_BodyReplayedViaGetBody174=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method175--- PASS: TestScriptTokenBadJSON (0.01s)176=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess177=== CONT TestResolveStorePath1782026/10/01 13:01:22 WARN Rate limiter enabled after throttle name=server-test rate=5179--- PASS: TestResolveStorePath (0.00s)180=== CONT TestRateLimiterFeedback181=== RUN TestRateLimiterFeedback/429_enables_limiter182=== PAUSE TestRateLimiterFeedback/429_enables_limiter183=== RUN TestRateLimiterFeedback/503_enables_limiter184=== PAUSE TestRateLimiterFeedback/503_enables_limiter185=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter186=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter187=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter188=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter189=== CONT TestPathInfoHashCompatibility190=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)191=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)192=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon193=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon194=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI196=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512198=== CONT TestParsePathInfoJSONMultiplePaths199=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== CONT TestParsePathInfoJSON204=== RUN TestParsePathInfoJSON/Nix_format205=== PAUSE TestParsePathInfoJSON/Nix_format206=== RUN TestParsePathInfoJSON/Lix_format207=== PAUSE TestParsePathInfoJSON/Lix_format208=== RUN TestParsePathInfoJSON/empty_input209=== PAUSE TestParsePathInfoJSON/empty_input210=== RUN TestParsePathInfoJSON/whitespace_only211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== RUN TestParsePathInfoJSON/invalid_JSON213=== PAUSE TestParsePathInfoJSON/invalid_JSON214=== CONT TestGetStorePathHash215=== RUN TestGetStorePathHash/valid_store_path216=== PAUSE TestGetStorePathHash/valid_store_path217=== RUN TestGetStorePathHash/basename_without_hyphen_should_error218=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error219=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2202026/10/01 13:01:22 WARN Rate limiter enabled after throttle name=server-test rate=5221=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2232026/10/01 13:01:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49805224=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error225=== CONT TestStreamPushRequestLine2262026/10/01 13:01:22 ERROR Upload failed error=boom count=12272026/10/01 13:01:22 WARN Rate limiter backed off name=server-test rate=52282026/10/01 13:01:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49805229--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)230=== CONT TestSetClientTLSDoesNotMutateDefaultTransport231--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)232=== CONT TestSetClientTLS233=== RUN TestSetClientTLS/rejects_connection_without_client_cert234=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert235=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA236=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA237=== RUN TestSetClientTLS/preserves_debug_logging_transport238=== PAUSE TestSetClientTLS/preserves_debug_logging_transport239=== CONT TestClientSignaturesByStorePath240--- PASS: TestClientSignaturesByStorePath (0.00s)241=== CONT TestStreamPushReportsSignatures2422026/10/01 13:01:22 ERROR Upload failed error=boom count=1243--- PASS: TestStreamPushReportsSignatures (0.00s)244=== CONT TestStreamPushBatchesUnderLoad245--- PASS: TestStreamPushRequestLine (0.01s)246=== CONT TestStreamPushGivesUpOnDeadServer2472026/10/01 13:01:22 ERROR Upload failed error="connection refused" count=202482026/10/01 13:01:22 ERROR Server seems unavailable, giving up on batch untried=17249--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)250=== CONT TestStreamPushIsolatesFailures2512026/10/01 13:01:22 ERROR Upload failed error="bad path" count=3252--- PASS: TestStreamPushIsolatesFailures (0.00s)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 TestStreamPushReportsEveryPath261--- PASS: TestStreamPushReportsEveryPath (0.00s)262=== CONT TestShellSplitErrors263--- PASS: TestShellSplitErrors (0.00s)264=== CONT TestCaseHackSuffix265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== CONT TestUploadMultipart_SupersededByPeer/missing268--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)269 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)270 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)271=== CONT TestEncodeNixBase32/test_string_hash272=== CONT TestEncodeNixBase32/empty_input273--- PASS: TestEncodeNixBase32 (0.00s)274 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)275 --- PASS: TestEncodeNixBase32/empty_input (0.00s)276=== CONT TestFilterOversizedClosures/no_limit_keeps_everything277=== CONT TestFilterOversizedClosures/all_closures_skipped2782026/10/01 13:01:22 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50279=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2802026/10/01 13:01:22 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=2000281--- PASS: TestFilterOversizedClosures (0.00s)282 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)283 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)284 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)285=== CONT TestSetClientTLSErrors/missing_cert_file286=== CONT TestSetClientTLSErrors/invalid_ca_file287=== CONT TestSetClientTLSErrors/missing_ca_file288=== CONT TestSetClientTLSErrors/missing_key_file289=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum290=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts291=== CONT TestPartSizeForNAR/small_stays_at_minimum292=== CONT TestPartSizeForNAR/capped_at_5_GiB293=== CONT TestPartSizeForNAR/5_TiB_S3_max_object294=== CONT TestPartSizeForNAR/zero_stays_at_minimum295=== CONT TestPartSizeForNAR/1_TiB296--- PASS: TestPartSizeForNAR (0.00s)297 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)298 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)299 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)300 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)301 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)302 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)303 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)304=== CONT TestPathInfoCACompatibility/null_ca_field305=== CONT TestPathInfoCACompatibility/new_structured_format_-_text306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== CONT TestPathInfoCACompatibility/old_string_format_-_text308=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method309--- PASS: TestPathInfoCACompatibility (0.01s)310 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)311 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)312 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)313 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)315=== CONT TestRateLimiterFeedback/429_enables_limiter316--- PASS: TestSetClientTLSErrors (0.01s)317 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)318 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)319 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3212026/10/01 13:01:22 WARN Rate limiter enabled after throttle name=server-test rate=53222026/10/01 13:01:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:498173232026/10/01 13:01:22 WARN Rate limiter backed off name=server-test rate=5324=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter325=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter326=== CONT TestRateLimiterFeedback/503_enables_limiter327--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)328=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)329=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths330=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512331=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI332=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon333--- PASS: TestPathInfoHashCompatibility (0.00s)334 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)336 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)337 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)338=== CONT TestParsePathInfoJSON/Nix_format339=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths340--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)343=== CONT TestParsePathInfoJSON/whitespace_only344=== CONT TestParsePathInfoJSON/invalid_JSON345=== CONT TestGetStorePathHash/valid_store_path346=== CONT TestParsePathInfoJSON/empty_input347=== CONT TestParsePathInfoJSON/Lix_format348--- PASS: TestParsePathInfoJSON (0.00s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)353 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)354=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error355=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error356=== CONT TestGetStorePathHash/basename_without_hyphen_should_error357--- PASS: TestGetStorePathHash (0.00s)358 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)361 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)362=== CONT TestSetClientTLS/rejects_connection_without_client_cert3632026/10/01 13:01:22 WARN Rate limiter enabled after throttle name=server-test rate=53642026/10/01 13:01:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:498233652026/10/01 13:01:22 WARN Rate limiter backed off name=server-test rate=5366--- PASS: TestRateLimiterFeedback (0.00s)367 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)371=== CONT TestSetClientTLS/preserves_debug_logging_transport372--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)373=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA374=== CONT TestConvertHashToNix32/SRI_format_to_Nix32375=== CONT TestConvertHashToNix32/invalid_format376=== CONT TestConvertHashToNix32/already_Nix32_format377--- PASS: TestConvertHashToNix32 (0.00s)378 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)379 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)380 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)381--- PASS: TestDumpPathWriterError (0.05s)3822026/10/01 13:01:22 http: TLS handshake error from 127.0.0.1:49825: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)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.06s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.08s)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 "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-14421-1556620820/postgres1621501437/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-14421-1556620820/postgres1621501437/data -l logfile start421422/nix/var/nix/builds/nix-14421-1556620820/postgres1621501437:5432 - no response4232026-10-01 13:01:24.589 UTC [14473] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 13:01:24.590 UTC [14473] LOG: listening on Unix socket "/nix/var/nix/builds/nix-14421-1556620820/postgres1621501437/.s.PGSQL.5432"4252026-10-01 13:01:24.592 UTC [14480] LOG: database system was shut down at 2026-10-01 13:01:24 UTC4262026-10-01 13:01:24.592 UTC [14473] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-14421-1556620820/postgres1621501437:5432 - accepting connections428{"timestamp":"2026-10-01T13:01:24.808457Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6ab68c19-0368-450d-82f4-060fc72737ca","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(9)"}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:01:25 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 13:01:26 INFO lead: released remote=192.0.2.1:12344762026/10/01 13:01:26 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 13:01:27 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (2.34s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestLeadEndsWhenItsConnectionHangs4822026/10/01 13:01:27 INFO lead: acquired remote=192.0.2.1:12344832026-10-01 13:01:28.614 UTC [14515] FATAL: terminating connection due to administrator command4842026/10/01 13:01:28 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 13:01:29 WARN lead: lock connection lost error="timeout: context deadline exceeded"4862026/10/01 13:01:29 INFO lead: released remote=192.0.2.1:12344872026/10/01 13:01:30 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:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 13:01:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"652--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)653=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle655=== RUN TestProxyWriteTimeout656=== PAUSE TestProxyWriteTimeout657=== RUN TestPendingClosureWriteTimeout658=== PAUSE TestPendingClosureWriteTimeout659=== RUN TestIsValidUploadKey660=== PAUSE TestIsValidUploadKey661=== RUN TestUploadHandlersRejectInvalidKeys662=== PAUSE TestUploadHandlersRejectInvalidKeys663=== RUN TestUploadHandlersRejectOversizedBody664=== PAUSE TestUploadHandlersRejectOversizedBody665=== RUN TestService_cleanupPendingClosuresHandler666=== PAUSE TestService_cleanupPendingClosuresHandler667=== RUN TestService_createPendingClosureHandler668=== PAUSE TestService_createPendingClosureHandler669=== RUN TestService_verifyS3Integrity670=== PAUSE TestService_verifyS3Integrity671=== RUN TestCompleteMultipartUnregistered672=== PAUSE TestCompleteMultipartUnregistered673=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT674=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT675=== CONT TestReadProxyConditionalGet676=== CONT TestCommitRacingPendingCleanupKeepsObjects677=== CONT TestSweepSkipsRowsLockedByPush678=== CONT TestPresignedUploadRegisteredBeforeCommit679=== CONT TestPush_CompleteCommitsEveryRoot680=== CONT TestService_AuthMiddleware681=== CONT TestPushWaitsForSweepHoldingRow682=== CONT TestSweepRechecksPendingAfterLocking683=== CONT TestGetExistingObjectsLocksRows684=== CONT TestRegisterCompletedObjectNeedsPendingRow6852026/10/01 13:01:30 INFO Aborted multipart uploads count=0 kept=06862026/10/01 13:01:30 WARN Force mode enabled - objects will be deleted immediately without grace period6872026/10/01 13:01:30 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=06882026/10/01 13:01:30 INFO Vacuumed table table=pending_closures6892026/10/01 13:01:30 INFO Vacuumed table table=pending_objects6902026/10/01 13:01:30 INFO Vacuumed table table=multipart_uploads6912026/10/01 13:01:30 INFO Vacuumed table table=closures6922026/10/01 13:01:30 INFO Vacuumed table table=objects693--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)694=== CONT TestReadRedirectKeepsNarinfoProxied6952026/10/01 13:01:30 INFO Received uploads request method=POST path=/api/pending_closures6962026/10/01 13:01:30 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst6972026/10/01 13:01:30 INFO Received uploads request method=POST path=/api/pending_closures698--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.64s)699=== CONT TestPush_OverlappingRootsStoreOneRowPerKey7002026/10/01 13:01:31 INFO Received push request method=POST path=/api/pushes7012026/10/01 13:01:31 INFO Received complete push request method=POST path=/api/pushes/1/complete702--- PASS: TestPush_CompleteCommitsEveryRoot (0.90s)703=== CONT TestReadRedirectUsesPublicS3URL7042026/10/01 13:01:31 INFO Aborted multipart uploads count=0 kept=07052026/10/01 13:01:31 WARN Force mode enabled - objects will be deleted immediately without grace period7062026/10/01 13:01:31 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=07072026/10/01 13:01:31 INFO Vacuumed table table=pending_closures7082026/10/01 13:01:31 INFO Vacuumed table table=pending_objects7092026/10/01 13:01:31 INFO Vacuumed table table=multipart_uploads7102026/10/01 13:01:31 INFO Vacuumed table table=closures7112026/10/01 13:01:31 INFO Vacuumed table table=objects7122026/10/01 13:01:31 INFO Aborted multipart uploads count=0 kept=07132026/10/01 13:01:31 WARN Force mode enabled - objects will be deleted immediately without grace period7142026/10/01 13:01:31 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=07152026/10/01 13:01:31 INFO Vacuumed table table=pending_closures7162026/10/01 13:01:31 INFO Vacuumed table table=pending_objects7172026/10/01 13:01:31 INFO Vacuumed table table=multipart_uploads7182026/10/01 13:01:31 INFO Vacuumed table table=closures7192026/10/01 13:01:31 INFO Vacuumed table table=objects720--- PASS: TestSweepSkipsRowsLockedByPush (1.04s)721=== CONT TestReadProxyRangeRequest7222026/10/01 13:01:31 INFO Received uploads request method=POST path=/api/pending_closures723--- PASS: TestReadProxyConditionalGet (1.31s)724=== CONT TestRedundantMultipartUpload7252026/10/01 13:01:31 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"726--- PASS: TestService_AuthMiddleware (1.46s)727=== CONT TestCompletedNarNotReofferedAcrossClosures728--- PASS: TestPushWaitsForSweepHoldingRow (1.62s)729=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7302026/10/01 13:01:31 INFO Aborted multipart uploads count=0 kept=07312026/10/01 13:01:31 WARN Force mode enabled - objects will be deleted immediately without grace period7322026/10/01 13:01:31 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=07332026/10/01 13:01:31 INFO Vacuumed table table=pending_closures7342026/10/01 13:01:32 INFO Vacuumed table table=pending_objects7352026/10/01 13:01:32 INFO Vacuumed table table=multipart_uploads7362026/10/01 13:01:32 INFO Vacuumed table table=closures7372026/10/01 13:01:32 INFO Vacuumed table table=objects738--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.78s)739=== CONT TestReadProxyDisabled740--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.84s)741=== CONT TestReadRedirectNar742--- PASS: TestGetExistingObjectsLocksRows (1.99s)743=== CONT TestClientFallsBackToClosures744--- PASS: TestReadRedirectKeepsNarinfoProxied (1.59s)745=== CONT TestFailedS3DeleteKeepsTombstone7462026/10/01 13:01:32 INFO Received push request method=POST path=/api/pushes747--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.77s)748=== CONT TestForceGCDuringPushOffersSweptObject749=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows750=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows751=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check752=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check753=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection754--- PASS: TestReadRedirectUsesPublicS3URL (1.68s)755=== CONT TestGCSweepDeliversEachKeyOnce756--- PASS: TestReadProxyRangeRequest (1.76s)757=== CONT TestTombstonedObjectOfferedWithoutWaiting7582026/10/01 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures7592026/10/01 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures7602026/10/01 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures7612026/10/01 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures7622026/10/01 13:01:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7632026/10/01 13:01:34 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LmEwNjg4ODYwLTAyZTUtNGM5YS1hODlmLTNiMzhkNjQ1ZDczMngxNzkwODU5NjkzNzkwMjkzMDAw764--- PASS: TestReadProxyDisabled (2.09s)765=== CONT TestGCSweepSkipsPendingObjects7662026/10/01 13:01:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LmEwNjg4ODYwLTAyZTUtNGM5YS1hODlmLTNiMzhkNjQ1ZDczMngxNzkwODU5NjkzNzkwMjkzMDAw parts=1767--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.25s)768=== CONT TestDeduplicatedObjectsRecordedAsPending769--- PASS: TestReadRedirectNar (2.39s)770=== CONT TestPushDedupSurvivesConcurrentGC7712026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7722026/10/01 13:01:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7732026/10/01 13:01:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LmY3MmM4ZDc2LTg2NDgtNDMxNi1hMzcyLTcwYjFhYmJlYTM4Y3gxNzkwODU5NjkzMzAwODAzMDAw parts=127742026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7752026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7762026/10/01 13:01:35 INFO Aborted multipart uploads count=0 kept=07772026/10/01 13:01:35 WARN Force mode enabled - objects will be deleted immediately without grace period7782026/10/01 13:01:35 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."7792026/10/01 13:01:35 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."780--- PASS: TestFailedS3DeleteKeepsTombstone (2.84s)781=== CONT TestGCMetrics7822026/10/01 13:01:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7832026/10/01 13:01:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LjEzMjhmNjY1LTk3YzAtNGIzYy1hYTE3LTZlNWEwMWE1MjZkN3gxNzkwODU5NjkzNTI1MjM0MDAw parts=127842026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures785--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.65s)786=== CONT TestGCBugBareHashReferences7872026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7882026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7892026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/01 13:01:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)7912026/10/01 13:01:35 INFO Uploading m8c91aw8ri0v5pqybkvp3l2j6g16dp1i-b (248B)7922026/10/01 13:01:35 INFO Uploading r0l10k5n7qrz62a1sx4dvgizk4zqbv2k-shared-dep (136B)7932026/10/01 13:01:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7942026/10/01 13:01:35 WARN Failed to register uploaded object key=m8c91aw8ri0v5pqybkvp3l2j6g16dp1i.ls error="server returned 404: 404 page not found\n"7952026/10/01 13:01:35 WARN Failed to register uploaded object key=nar/1741ffpcdzzh3ygblylik7jlwdzs3b5p3hch8cwkx17pwp1fa5fs.nar.zst error="server returned 404: 404 page not found\n"7962026/10/01 13:01:35 WARN Failed to register uploaded object key=r0l10k5n7qrz62a1sx4dvgizk4zqbv2k.ls error="server returned 404: 404 page not found\n"7972026/10/01 13:01:35 WARN Failed to register uploaded object key=p163szhgavcxwixw9r4s3ap5h8lkn2hm.ls error="server returned 404: 404 page not found\n"7982026/10/01 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign7992026/10/01 13:01:35 INFO Signed narinfos id=2 count=28002026/10/01 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8012026/10/01 13:01:35 INFO Signed narinfos id=1 count=28022026/10/01 13:01:35 INFO Uploading 4 narinfos8032026/10/01 13:01:35 WARN Failed to register uploaded object key=p163szhgavcxwixw9r4s3ap5h8lkn2hm.narinfo error="server returned 404: 404 page not found\n"8042026/10/01 13:01:35 WARN Failed to register uploaded object key=m8c91aw8ri0v5pqybkvp3l2j6g16dp1i.narinfo error="server returned 404: 404 page not found\n"8052026/10/01 13:01:35 WARN Failed to register uploaded object key=r0l10k5n7qrz62a1sx4dvgizk4zqbv2k.narinfo error="server returned 404: 404 page not found\n"8062026/10/01 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8072026/10/01 13:01:35 WARN Failed to register uploaded object key=r0l10k5n7qrz62a1sx4dvgizk4zqbv2k.narinfo error="server returned 404: 404 page not found\n"8082026/10/01 13:01:35 INFO Completed upload id=18092026/10/01 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8102026/10/01 13:01:35 INFO Completed upload id=28112026/10/01 13:01:35 INFO Upload complete. (199ms)812=== NAME TestClientFallsBackToClosures813 client_pushes_test.go:112: Retrieved narinfo from S3:814 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientFallsBackToClosures1962573887/001/store/r0l10k5n7qrz62a1sx4dvgizk4zqbv2k-shared-dep815 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst816 Compression: zstd817 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82818 NarSize: 136819 References: 820 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n821 client_pushes_test.go:112: Retrieved narinfo from S3:822 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientFallsBackToClosures1962573887/001/store/p163szhgavcxwixw9r4s3ap5h8lkn2hm-a823 URL: nar/1741ffpcdzzh3ygblylik7jlwdzs3b5p3hch8cwkx17pwp1fa5fs.nar.zst824 Compression: zstd825 NarHash: sha256:1741ffpcdzzh3ygblylik7jlwdzs3b5p3hch8cwkx17pwp1fa5fs826 NarSize: 248827 References: /nix/var/nix/builds/nix-14421-1556620820/TestClientFallsBackToClosures1962573887/001/store/r0l10k5n7qrz62a1sx4dvgizk4zqbv2k-shared-dep828 CA: text:sha256:143nma6hs4dhmpbps0id62yinplvcf6c2vv26vd75rzyx5vzspxa829 client_pushes_test.go:112: Retrieved narinfo from S3:830 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientFallsBackToClosures1962573887/001/store/m8c91aw8ri0v5pqybkvp3l2j6g16dp1i-b831 URL: nar/1741ffpcdzzh3ygblylik7jlwdzs3b5p3hch8cwkx17pwp1fa5fs.nar.zst832 Compression: zstd833 NarHash: sha256:1741ffpcdzzh3ygblylik7jlwdzs3b5p3hch8cwkx17pwp1fa5fs834 NarSize: 248835 References: /nix/var/nix/builds/nix-14421-1556620820/TestClientFallsBackToClosures1962573887/001/store/r0l10k5n7qrz62a1sx4dvgizk4zqbv2k-shared-dep836 CA: text:sha256:143nma6hs4dhmpbps0id62yinplvcf6c2vv26vd75rzyx5vzspxa837--- PASS: TestClientFallsBackToClosures (3.35s)838=== CONT TestGCAdvisoryLockBlocksConcurrentRun839--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.94s)840=== CONT TestLeadEndsOnShutdown8412026/10/01 13:01:35 INFO Aborted multipart uploads count=0 kept=08422026/10/01 13:01:35 WARN Force mode enabled - objects will be deleted immediately without grace period8432026/10/01 13:01:35 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=08442026/10/01 13:01:35 INFO Vacuumed table table=pending_closures8452026/10/01 13:01:35 INFO Vacuumed table table=pending_objects8462026/10/01 13:01:35 INFO Vacuumed table table=multipart_uploads8472026/10/01 13:01:35 INFO Vacuumed table table=closures8482026/10/01 13:01:35 INFO Vacuumed table table=objects849--- PASS: TestGCSweepDeliversEachKeyOnce (3.01s)850=== CONT TestLeadElectsOneAndHandsOver8512026/10/01 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures852--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.91s)853=== CONT TestConnectWaitsForAPeerMigration8542026/10/01 13:01:36 INFO Received uploads request method=POST path=/api/pending_closures855--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.39s)856=== CONT TestResolveDBConnectionString857=== RUN TestResolveDBConnectionString/flag_wins858=== PAUSE TestResolveDBConnectionString/flag_wins859=== RUN TestResolveDBConnectionString/file_when_flag_empty860=== PAUSE TestResolveDBConnectionString/file_when_flag_empty861=== RUN TestResolveDBConnectionString/missing_file_is_an_error862=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error863=== RUN TestResolveDBConnectionString/PGHOST_allows_empty864=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty865=== RUN TestResolveDBConnectionString/nothing_configured866=== PAUSE TestResolveDBConnectionString/nothing_configured867=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8682026/10/01 13:01:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8692026/10/01 13:01:36 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LjA5YmYwNDk3LWVkNmEtNDEyYi1iNjU3LTQwMzdiNmJlMzNkNHgxNzkwODU5Njk1MTc2NjU1MDAw error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"8702026/10/01 13:01:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LjVhMGVhYWMzLTY5NzUtNDE5ZC05MGU0LTA3ZmI2YjgwNzQxOHgxNzkwODU5Njk1MTMyOTAwMDAw parts=128712026/10/01 13:01:36 INFO Received cleanup request method=DELETE path=/api/pending_closures8722026/10/01 13:01:36 INFO Aborted multipart uploads count=1 kept=0873--- PASS: TestRedundantMultipartUpload (5.11s)874=== CONT TestReadProxyRootRedirectsToIndexHTML8752026/10/01 13:01:36 INFO Received uploads request method=POST path=/api/pending_closures8762026/10/01 13:01:36 INFO Aborted multipart uploads count=0 kept=08772026/10/01 13:01:36 WARN Force mode enabled - objects will be deleted immediately without grace period8782026/10/01 13:01: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=08792026/10/01 13:01:36 INFO Vacuumed table table=pending_closures8802026/10/01 13:01:36 INFO Vacuumed table table=pending_objects8812026/10/01 13:01:36 INFO Vacuumed table table=multipart_uploads8822026/10/01 13:01:36 INFO Vacuumed table table=closures8832026/10/01 13:01:37 INFO Vacuumed table table=objects884--- PASS: TestGCSweepSkipsPendingObjects (2.93s)885=== CONT TestClientCADerivations8862026/10/01 13:01:37 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/01 13:01:37 INFO Aborted multipart uploads count=0 kept=08882026/10/01 13:01:37 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=08892026/10/01 13:01:37 INFO Vacuumed table table=pending_closures8902026/10/01 13:01:37 INFO Vacuumed table table=pending_objects8912026/10/01 13:01:37 INFO Vacuumed table table=multipart_uploads8922026/10/01 13:01:37 INFO Vacuumed table table=closures8932026/10/01 13:01:37 INFO Vacuumed table table=objects8942026/10/01 13:01:37 INFO Aborted multipart uploads count=0 kept=08952026/10/01 13:01:37 WARN Force mode enabled - objects will be deleted immediately without grace period8962026/10/01 13:01: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=08972026/10/01 13:01:37 INFO Vacuumed table table=pending_closures8982026/10/01 13:01:37 INFO Vacuumed table table=pending_objects8992026/10/01 13:01:37 INFO Vacuumed table table=multipart_uploads9002026/10/01 13:01:37 INFO Vacuumed table table=closures9012026/10/01 13:01:37 INFO Vacuumed table table=objects902--- PASS: TestPushDedupSurvivesConcurrentGC (3.10s)903=== CONT TestClientPushesUseOnePush9042026/10/01 13:01:37 INFO Aborted multipart uploads count=0 kept=09052026/10/01 13:01:37 WARN Force mode enabled - objects will be deleted immediately without grace period9062026/10/01 13:01: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=09072026/10/01 13:01:37 INFO Vacuumed table table=pending_closures9082026/10/01 13:01:38 INFO Vacuumed table table=pending_objects9092026/10/01 13:01:38 INFO Vacuumed table table=multipart_uploads9102026/10/01 13:01:38 INFO Vacuumed table table=closures9112026/10/01 13:01:38 INFO Vacuumed table table=objects912--- PASS: TestGCMetrics (2.78s)913=== CONT TestPinProtectsFromGC914--- PASS: TestGCBugBareHashReferences (3.22s)915=== CONT TestClientSharedPathCommittedMidPush9162026/10/01 13:01:38 INFO lead: acquired remote=192.0.2.1:1234917--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.37s)918=== CONT TestClientWithDependencies9192026/10/01 13:01:39 INFO lead: acquired remote=192.0.2.1:12349202026/10/01 13:01:39 INFO lead: released remote=192.0.2.1:1234921--- PASS: TestLeadEndsOnShutdown (4.08s)922=== CONT TestCacheStatsHandler923--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.26s)924=== CONT TestClientMultipleUploads9252026/10/01 13:01:40 INFO lead: released remote=192.0.2.1:1234926=== NAME TestClientCADerivations927 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-14421-1556620820/TestClientCADerivations2216008330/001/store/cqfd7d0yfs85wbv200xq9lawdd32v0kd-ca-test9282026/10/01 13:01:40 INFO lead: acquired remote=192.0.2.1:1234929 client_ca_test.go:139: Found 1 dependencies (including self)930--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.07s)931=== CONT TestClientIntegration9322026/10/01 13:01:40 INFO Received push request method=POST path=/api/pushes9332026/10/01 13:01:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9342026/10/01 13:01:40 INFO Uploading qxsvrhhb3p3y0p5cs8lbqyql8daa8wj4-a (248B)9352026/10/01 13:01:40 INFO Uploading aamz2hyjli379x7dwb663kwylslpnwv4-shared-dep (136B)9362026/10/01 13:01:40 WARN Failed to register uploaded object key=qxsvrhhb3p3y0p5cs8lbqyql8daa8wj4.ls error="server returned 404: 404 page not found\n"9372026/10/01 13:01:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9382026/10/01 13:01:40 WARN Failed to register uploaded object key=aamz2hyjli379x7dwb663kwylslpnwv4.ls error="server returned 404: 404 page not found\n"9392026/10/01 13:01:40 WARN Failed to register uploaded object key=nar/1rfab1yz6vx7cc78ccnawvz5rc4agvblkhdqlbsmc2mka5x5sp46.nar.zst error="server returned 404: 404 page not found\n"9402026/10/01 13:01:40 WARN Failed to register uploaded object key=q9410yr903akyvwyick45b4ym5pmmbjx.ls error="server returned 404: 404 page not found\n"9412026/10/01 13:01:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9422026/10/01 13:01:40 INFO Signed narinfos id=1 count=39432026/10/01 13:01:40 INFO Uploading 3 narinfos9442026/10/01 13:01:40 WARN Failed to register uploaded object key=qxsvrhhb3p3y0p5cs8lbqyql8daa8wj4.narinfo error="server returned 404: 404 page not found\n"9452026/10/01 13:01:40 WARN Failed to register uploaded object key=q9410yr903akyvwyick45b4ym5pmmbjx.narinfo error="server returned 404: 404 page not found\n"9462026/10/01 13:01:40 INFO Received complete push request method=POST path=/api/pushes/1/complete9472026/10/01 13:01:40 WARN Failed to register uploaded object key=aamz2hyjli379x7dwb663kwylslpnwv4.narinfo error="server returned 404: 404 page not found\n"9482026/10/01 13:01:40 INFO Received push request method=POST path=/api/pushes9492026/10/01 13:01:40 INFO Upload complete. (120ms)950=== NAME TestClientPushesUseOnePush951 client_pushes_test.go:97: Retrieved narinfo from S3:952 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientPushesUseOnePush992053131/001/store/aamz2hyjli379x7dwb663kwylslpnwv4-shared-dep953 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst954 Compression: zstd955 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82956 NarSize: 136957 References: 958 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n959 client_pushes_test.go:97: Retrieved narinfo from S3:960 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientPushesUseOnePush992053131/001/store/qxsvrhhb3p3y0p5cs8lbqyql8daa8wj4-a961 URL: nar/1rfab1yz6vx7cc78ccnawvz5rc4agvblkhdqlbsmc2mka5x5sp46.nar.zst962 Compression: zstd963 NarHash: sha256:1rfab1yz6vx7cc78ccnawvz5rc4agvblkhdqlbsmc2mka5x5sp46964 NarSize: 248965 References: /nix/var/nix/builds/nix-14421-1556620820/TestClientPushesUseOnePush992053131/001/store/aamz2hyjli379x7dwb663kwylslpnwv4-shared-dep966 CA: text:sha256:1pwbzgqq59j9x1md16jb3w2x11b61sbsrrgbrzam8l8nwyqpp8aq967 client_pushes_test.go:97: Retrieved narinfo from S3:968 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientPushesUseOnePush992053131/001/store/q9410yr903akyvwyick45b4ym5pmmbjx-b969 URL: nar/1rfab1yz6vx7cc78ccnawvz5rc4agvblkhdqlbsmc2mka5x5sp46.nar.zst970 Compression: zstd971 NarHash: sha256:1rfab1yz6vx7cc78ccnawvz5rc4agvblkhdqlbsmc2mka5x5sp46972 NarSize: 248973 References: /nix/var/nix/builds/nix-14421-1556620820/TestClientPushesUseOnePush992053131/001/store/aamz2hyjli379x7dwb663kwylslpnwv4-shared-dep974 CA: text:sha256:1pwbzgqq59j9x1md16jb3w2x11b61sbsrrgbrzam8l8nwyqpp8aq9752026/10/01 13:01:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9762026/10/01 13:01:40 INFO Uploading cqfd7d0yfs85wbv200xq9lawdd32v0kd-ca-test (144B)977=== NAME TestPinProtectsFromGC978 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-14421-1556620820/TestPinProtectsFromGC3147063466/001/store/43bsk55pqdq0qaw83dhhkck23wk3p847-pinned-file.txt979 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-14421-1556620820/TestPinProtectsFromGC3147063466/001/store/88xdfy3m4ccblbbiaxn6l2lpgiv38ix9-unpinned-file.txt9802026/10/01 13:01:40 WARN Failed to register uploaded object key=cqfd7d0yfs85wbv200xq9lawdd32v0kd.ls error="server returned 404: 404 page not found\n"9812026/10/01 13:01:40 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9822026/10/01 13:01:40 WARN Failed to register uploaded object key=log/86gzagphz8v2rl65h9i6sjbws0j1yccz-ca-test.drv error="server returned 404: 404 page not found\n"9832026/10/01 13:01:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9842026/10/01 13:01:40 INFO Signed narinfos id=1 count=19852026/10/01 13:01:40 INFO Uploading 1 narinfos9862026/10/01 13:01:40 INFO Received complete push request method=POST path=/api/pushes/1/complete9872026/10/01 13:01:40 WARN Failed to register uploaded object key=cqfd7d0yfs85wbv200xq9lawdd32v0kd.narinfo error="server returned 404: 404 page not found\n"988--- PASS: TestClientPushesUseOnePush (3.22s)989=== CONT TestClientErrorHandling990=== RUN TestClientErrorHandling/InvalidStorePath991=== PAUSE TestClientErrorHandling/InvalidStorePath992=== RUN TestClientErrorHandling/InvalidAuthToken993=== PAUSE TestClientErrorHandling/InvalidAuthToken994=== RUN TestClientErrorHandling/ServerNotAvailable995=== PAUSE TestClientErrorHandling/ServerNotAvailable996=== CONT TestService_AuthMiddleware_OIDC9972026/10/01 13:01:40 INFO Received push request method=POST path=/api/pushes9982026/10/01 13:01:40 INFO Upload complete. (207ms)999=== NAME TestClientCADerivations1000 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientCADerivations2216008330/001/store/cqfd7d0yfs85wbv200xq9lawdd32v0kd-ca-test1001 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1002 Compression: zstd1003 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1004 NarSize: 1441005 References: 1006 Deriver: /nix/var/nix/builds/nix-14421-1556620820/TestClientCADerivations2216008330/001/store/86gzagphz8v2rl65h9i6sjbws0j1yccz-ca-test.drv1007 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1008 client_ca_test.go:185: Checking for realisation files in S3...1009 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1010 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache10112026/10/01 13:01:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50009/oidc10122026/10/01 13:01:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10132026/10/01 13:01:40 INFO Uploading 43bsk55pqdq0qaw83dhhkck23wk3p847-pinned-file.txt (128B)10142026/10/01 13:01:40 WARN Failed to register uploaded object key=43bsk55pqdq0qaw83dhhkck23wk3p847.ls error="server returned 404: 404 page not found\n"10152026/10/01 13:01:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10162026/10/01 13:01:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10172026/10/01 13:01:40 INFO Signed narinfos id=1 count=110182026/10/01 13:01:40 INFO Uploading 1 narinfos10192026/10/01 13:01:40 INFO Received complete push request method=POST path=/api/pushes/1/complete10202026/10/01 13:01:40 WARN Failed to register uploaded object key=43bsk55pqdq0qaw83dhhkck23wk3p847.narinfo error="server returned 404: 404 page not found\n"1021 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket37?endpoint=http://localhost:49830®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-14421-1556620820/TestClientCADerivations2216008330/001/store'1022 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 110232026/10/01 13:01:40 INFO Upload complete. (144ms)1024--- PASS: TestClientCADerivations (3.90s)1025=== CONT TestService_ReadScope_PublicByDefault10262026/10/01 13:01:40 INFO Received push request method=POST path=/api/pushes10272026/10/01 13:01:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10282026/10/01 13:01:40 INFO Uploading 88xdfy3m4ccblbbiaxn6l2lpgiv38ix9-unpinned-file.txt (128B)10292026/10/01 13:01:40 WARN Failed to register uploaded object key=88xdfy3m4ccblbbiaxn6l2lpgiv38ix9.ls error="server returned 404: 404 page not found\n"10302026/10/01 13:01:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10312026/10/01 13:01:40 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10322026/10/01 13:01:40 INFO Signed narinfos id=2 count=110332026/10/01 13:01:40 INFO Uploading 1 narinfos10342026/10/01 13:01:41 INFO Received complete push request method=POST path=/api/pushes/2/complete10352026/10/01 13:01:41 WARN Failed to register uploaded object key=88xdfy3m4ccblbbiaxn6l2lpgiv38ix9.narinfo error="server returned 404: 404 page not found\n"10362026/10/01 13:01:41 INFO Upload complete. (73ms)10372026/10/01 13:01:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures10382026/10/01 13:01:41 INFO Garbage collection started10392026/10/01 13:01:41 INFO Aborted multipart uploads count=0 kept=010402026/10/01 13:01:41 WARN Force mode enabled - objects will be deleted immediately without grace period10412026/10/01 13:01:41 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=010422026/10/01 13:01:41 INFO Vacuumed table table=pending_closures10432026/10/01 13:01:41 INFO Vacuumed table table=pending_objects10442026/10/01 13:01:41 INFO Vacuumed table table=multipart_uploads10452026/10/01 13:01:41 INFO Received push request method=POST path=/api/pushes10462026/10/01 13:01:41 INFO Vacuumed table table=closures10472026/10/01 13:01:41 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10482026/10/01 13:01:41 INFO Uploading kwhkmnp60x6jbb4ib6g15qn8lvrjbafr-top (256B)10492026/10/01 13:01:41 INFO Uploading ir7fsw5p2v67fqbgqvff9dggldzp5yz9-shared-dep (136B)10502026/10/01 13:01:41 INFO Vacuumed table table=objects10512026/10/01 13:01:41 WARN Failed to register uploaded object key=ir7fsw5p2v67fqbgqvff9dggldzp5yz9.ls error="server returned 404: 404 page not found\n"10522026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/1wfw2xxd8wvsa144vvlcqz6hbhkd5rvcs80gam35nnlv9gwrgnyh.nar.zst error="server returned 404: 404 page not found\n"10532026/10/01 13:01:41 WARN Failed to register uploaded object key=kwhkmnp60x6jbb4ib6g15qn8lvrjbafr.ls error="server returned 404: 404 page not found\n"10542026/10/01 13:01:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10552026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10562026/10/01 13:01:41 INFO Signed narinfos id=1 count=210572026/10/01 13:01:41 INFO Uploading 2 narinfos10582026/10/01 13:01:41 INFO Received complete push request method=POST path=/api/pushes/1/complete10592026/10/01 13:01:41 WARN Failed to register uploaded object key=ir7fsw5p2v67fqbgqvff9dggldzp5yz9.narinfo error="server returned 404: 404 page not found\n"10602026/10/01 13:01:41 WARN Failed to register uploaded object key=kwhkmnp60x6jbb4ib6g15qn8lvrjbafr.narinfo error="server returned 404: 404 page not found\n"10612026/10/01 13:01:41 INFO Upload complete. (109ms)1062=== NAME TestClientSharedPathCommittedMidPush1063 client_integration_test.go:680: Retrieved narinfo from S3:1064 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientSharedPathCommittedMidPush915523135/001/store/ir7fsw5p2v67fqbgqvff9dggldzp5yz9-shared-dep1065 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1066 Compression: zstd1067 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821068 NarSize: 1361069 References: 1070 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1071 client_integration_test.go:680: Retrieved narinfo from S3:1072 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientSharedPathCommittedMidPush915523135/001/store/kwhkmnp60x6jbb4ib6g15qn8lvrjbafr-top1073 URL: nar/1wfw2xxd8wvsa144vvlcqz6hbhkd5rvcs80gam35nnlv9gwrgnyh.nar.zst1074 Compression: zstd1075 NarHash: sha256:1wfw2xxd8wvsa144vvlcqz6hbhkd5rvcs80gam35nnlv9gwrgnyh1076 NarSize: 2561077 References: /nix/var/nix/builds/nix-14421-1556620820/TestClientSharedPathCommittedMidPush915523135/001/store/ir7fsw5p2v67fqbgqvff9dggldzp5yz9-shared-dep1078 CA: text:sha256:1idv3dbc3ldqsrvhi9r05s2qancnsg45ciffcpdm71rqq7xfsga41079--- PASS: TestClientSharedPathCommittedMidPush (2.65s)1080=== CONT TestService_RequireScope_OIDC10812026/10/01 13:01:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50042/oidc1082=== NAME TestClientWithDependencies1083 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-14421-1556620820/TestClientWithDependencies2881557373/001/store/nd56nqqrhiyv6ypxznyg4fcv0adgyyik-test-script1084--- PASS: TestCacheStatsHandler (1.62s)1085=== CONT TestPush_RejectsBadRequests1086=== NAME TestClientWithDependencies1087 client_integration_test.go:615: Found 1 dependencies (including self)10882026/10/01 13:01:41 INFO Received push request method=POST path=/api/pushes10892026/10/01 13:01:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10902026/10/01 13:01:41 INFO Uploading nd56nqqrhiyv6ypxznyg4fcv0adgyyik-test-script (136B)10912026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10922026/10/01 13:01:41 WARN Failed to register uploaded object key=nd56nqqrhiyv6ypxznyg4fcv0adgyyik.ls error="server returned 404: 404 page not found\n"10932026/10/01 13:01:41 WARN Failed to register uploaded object key=log/h311k4vbrm9mmrb8278mp408xzffgc7n-test-script.drv error="server returned 404: 404 page not found\n"10942026/10/01 13:01:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10952026/10/01 13:01:41 INFO Signed narinfos id=1 count=110962026/10/01 13:01:41 INFO Uploading 1 narinfos10972026/10/01 13:01:41 INFO Received complete push request method=POST path=/api/pushes/1/complete10982026/10/01 13:01:41 WARN Failed to register uploaded object key=nd56nqqrhiyv6ypxznyg4fcv0adgyyik.narinfo error="server returned 404: 404 page not found\n"10992026/10/01 13:01:41 INFO Upload complete. (107ms)1100 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-14421-1556620820/TestClientWithDependencies2881557373/001/store) requires matching store prefix1101--- PASS: TestClientWithDependencies (2.54s)1102=== CONT TestPush_SignsNarinfosOfItsPendingObjects1103=== NAME TestClientMultipleUploads1104 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-14421-1556620820/TestClientMultipleUploads940509722/001/store/fnsrqp4ab9w6hg5lanbvz62w02rfmd76-test-file-0.txt1105 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-14421-1556620820/TestClientMultipleUploads940509722/001/store/bp4w8afxpm137sbfx2xcsz9nl535gn09-test-file-1.txt1106 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-14421-1556620820/TestClientMultipleUploads940509722/001/store/0821q5s2vwx0f8ynjbjdnvjs4jcimfs8-test-file-2.txt11072026/10/01 13:01:41 INFO lead: released remote=192.0.2.1:12341108--- PASS: TestLeadElectsOneAndHandsOver (5.80s)1109=== CONT TestCacheConfigHandler1110=== RUN TestCacheConfigHandler/full_config,_no_issuer1111=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1112=== RUN TestCacheConfigHandler/no_cache_url_configured1113=== PAUSE TestCacheConfigHandler/no_cache_url_configured1114=== RUN TestCacheConfigHandler/no_signing_keys1115=== PAUSE TestCacheConfigHandler/no_signing_keys1116=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1117=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1118=== CONT TestMultipartCleanup11192026/10/01 13:01:41 INFO Received push request method=POST path=/api/pushes11202026/10/01 13:01:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11212026/10/01 13:01:41 INFO Uploading 0821q5s2vwx0f8ynjbjdnvjs4jcimfs8-test-file-2.txt (160B)11222026/10/01 13:01:41 INFO Uploading bp4w8afxpm137sbfx2xcsz9nl535gn09-test-file-1.txt (160B)11232026/10/01 13:01:41 INFO Uploading fnsrqp4ab9w6hg5lanbvz62w02rfmd76-test-file-0.txt (160B)11242026/10/01 13:01:41 WARN Failed to register uploaded object key=0821q5s2vwx0f8ynjbjdnvjs4jcimfs8.ls error="server returned 404: 404 page not found\n"11252026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11262026/10/01 13:01:41 WARN Failed to register uploaded object key=fnsrqp4ab9w6hg5lanbvz62w02rfmd76.ls error="server returned 404: 404 page not found\n"11272026/10/01 13:01:41 WARN Failed to register uploaded object key=bp4w8afxpm137sbfx2xcsz9nl535gn09.ls error="server returned 404: 404 page not found\n"11282026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11292026/10/01 13:01:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11302026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11312026/10/01 13:01:41 INFO Signed narinfos id=1 count=311322026/10/01 13:01:41 INFO Uploading 3 narinfos11332026/10/01 13:01:41 WARN Failed to register uploaded object key=bp4w8afxpm137sbfx2xcsz9nl535gn09.narinfo error="server returned 404: 404 page not found\n"11342026/10/01 13:01:41 INFO Received complete push request method=POST path=/api/pushes/1/complete11352026/10/01 13:01:41 WARN Failed to register uploaded object key=fnsrqp4ab9w6hg5lanbvz62w02rfmd76.narinfo error="server returned 404: 404 page not found\n"11362026/10/01 13:01:41 WARN Failed to register uploaded object key=0821q5s2vwx0f8ynjbjdnvjs4jcimfs8.narinfo error="server returned 404: 404 page not found\n"11372026/10/01 13:01:41 INFO Upload complete. (114ms)1138=== NAME TestClientMultipleUploads1139 client_integration_test.go:369: Uploaded 3 paths in 147.775083ms1140--- PASS: TestClientMultipleUploads (1.88s)1141=== CONT TestService_ReadAuthMiddleware1142=== NAME TestClientIntegration1143 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-14421-1556620820/TestClientIntegration304766358/002/store/8yrsw3njg91fdpcxwbcw0v95srsfrck5-test-file.txt1144=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1145=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1146=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1147=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1148=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1149=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1150=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1151=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1152=== CONT TestReadProxyOutlastsServerWriteTimeout11532026/10/01 13:01:41 INFO Received push request method=POST path=/api/pushes11542026/10/01 13:01:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11552026/10/01 13:01:41 INFO Uploading 8yrsw3njg91fdpcxwbcw0v95srsfrck5-test-file.txt (152B)11562026/10/01 13:01:41 WARN Failed to register uploaded object key=8yrsw3njg91fdpcxwbcw0v95srsfrck5.ls error="server returned 404: 404 page not found\n"11572026/10/01 13:01:41 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11582026/10/01 13:01:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11592026/10/01 13:01:41 INFO Signed narinfos id=1 count=111602026/10/01 13:01:41 INFO Uploading 1 narinfos11612026/10/01 13:01:41 INFO Received complete push request method=POST path=/api/pushes/1/complete11622026/10/01 13:01:41 WARN Failed to register uploaded object key=8yrsw3njg91fdpcxwbcw0v95srsfrck5.narinfo error="server returned 404: 404 page not found\n"11632026/10/01 13:01:42 INFO Upload complete. (138ms)11642026/10/01 13:01:42 INFO All 1 paths already cached1165=== NAME TestClientIntegration1166 client_integration_test.go:312: Retrieved narinfo from S3:1167 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestClientIntegration304766358/002/store/8yrsw3njg91fdpcxwbcw0v95srsfrck5-test-file.txt1168 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1169 Compression: zstd1170 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11171 NarSize: 1521172 References: 1173 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11174 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1175 client_integration_test.go:313: Decompressed .ls content (64 bytes):1176 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1177 client_integration_test.go:316: Testing garbage collection...11782026/10/01 13:01:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures11792026/10/01 13:01:42 INFO Garbage collection started11802026/10/01 13:01:42 INFO Aborted multipart uploads count=0 kept=011812026/10/01 13:01:42 WARN Force mode enabled - objects will be deleted immediately without grace period11822026/10/01 13:01:42 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=01183--- PASS: TestService_ReadScope_PublicByDefault (1.19s)1184=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11852026/10/01 13:01:42 INFO Vacuumed table table=pending_closures11862026/10/01 13:01:42 INFO Vacuumed table table=pending_objects11872026/10/01 13:01:42 INFO Vacuumed table table=multipart_uploads11882026/10/01 13:01:42 INFO Vacuumed table table=closures11892026/10/01 13:01:42 INFO Vacuumed table table=objects1190=== RUN TestService_RequireScope_OIDC/builder_may_write1191=== PAUSE TestService_RequireScope_OIDC/builder_may_write1192=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1193=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1194=== RUN TestService_RequireScope_OIDC/ops_may_admin1195=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1196=== RUN TestService_RequireScope_OIDC/ops_may_not_write1197=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1198=== RUN TestService_RequireScope_OIDC/reader_may_not_write1199=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1200=== RUN TestService_RequireScope_OIDC/static_token_may_admin1201=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1202=== RUN TestService_RequireScope_OIDC/static_token_may_write1203=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1204=== RUN TestService_RequireScope_OIDC/reader_may_read1205=== PAUSE TestService_RequireScope_OIDC/reader_may_read1206=== RUN TestService_RequireScope_OIDC/writer_implies_read1207=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1208=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1209=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1210=== CONT TestReadProxyHead1211=== RUN TestPush_RejectsBadRequests/no_roots1212=== PAUSE TestPush_RejectsBadRequests/no_roots1213=== RUN TestPush_RejectsBadRequests/no_objects1214=== PAUSE TestPush_RejectsBadRequests/no_objects1215=== RUN TestPush_RejectsBadRequests/bad_root1216=== PAUSE TestPush_RejectsBadRequests/bad_root1217=== RUN TestPush_RejectsBadRequests/root_not_in_objects1218=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1219=== CONT TestService_AuthMiddleware_MTLSProxyHeader12202026/10/01 13:01:42 INFO Received push request method=POST path=/api/pushes12212026/10/01 13:01:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12222026/10/01 13:01:42 INFO Signed narinfos id=1 count=11223--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.37s)1224=== CONT TestReadProxyInvalidPath1225--- PASS: TestConnectWaitsForAPeerMigration (6.98s)1226=== CONT TestUploadHandlersRejectInvalidKeys1227=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1228=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1229=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1230=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1231=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1232=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1233=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1234=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1235=== CONT TestReadProxy40412362026/10/01 13:01:43 INFO Received uploads request method=POST path=/api/pending_closures12372026/10/01 13:01:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=012382026/10/01 13:01:43 INFO Received create pin request method=POST path=/api/pins/myapp12392026/10/01 13:01:43 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-14421-1556620820/TestPinProtectsFromGC3147063466/001/store/43bsk55pqdq0qaw83dhhkck23wk3p847-pinned-file.txt narinfo_key=43bsk55pqdq0qaw83dhhkck23wk3p847.narinfo12402026/10/01 13:01:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures12412026/10/01 13:01:43 INFO Garbage collection started12422026/10/01 13:01:43 INFO Aborted multipart uploads count=0 kept=012432026/10/01 13:01:43 WARN Force mode enabled - objects will be deleted immediately without grace period12442026/10/01 13:01: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=012452026/10/01 13:01:43 INFO Vacuumed table table=pending_closures12462026/10/01 13:01:43 INFO Vacuumed table table=pending_objects12472026/10/01 13:01:43 INFO Vacuumed table table=multipart_uploads12482026/10/01 13:01:43 INFO Vacuumed table table=closures12492026/10/01 13:01:43 INFO Vacuumed table table=objects12502026/10/01 13:01:43 INFO Received cleanup request method=DELETE path=/api/pending_closures12512026/10/01 13:01:43 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket50/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12522026/10/01 13:01:43 INFO Aborted multipart uploads count=0 kept=112532026/10/01 13:01:43 INFO Received cleanup request method=DELETE path=/api/pending_closures12542026/10/01 13:01:43 INFO Aborted multipart uploads count=1 kept=01255--- PASS: TestMultipartCleanup (1.61s)1256=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1257--- PASS: TestService_ReadAuthMiddleware (1.45s)1258=== CONT TestCompleteMultipartUnregistered12592026/10/01 13:01:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12602026/10/01 13:01:43 WARN mTLS auth: bound subjects configured but subject DN unavailable12612026/10/01 13:01:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1262--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.56s)1263=== CONT TestReadProxyNarStreaming1264--- PASS: TestReadProxyHead (1.56s)1265=== CONT TestService_verifyS3Integrity12662026/10/01 13:01:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01267=== NAME TestClientIntegration1268 client_integration_test.go:323: Objects in database after GC:1269 client_integration_test.go:323: Successfully deleted all objects with GC --force1270--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.58s)1271=== CONT TestService_createPendingClosureHandler1272--- PASS: TestClientIntegration (3.52s)1273=== CONT TestReadProxyNarinfoAlreadyDecompressed1274--- PASS: TestReadProxyInvalidPath (1.44s)1275=== CONT TestService_cleanupPendingClosuresHandler1276--- PASS: TestReadProxy404 (1.64s)1277=== CONT TestUploadHandlersRejectOversizedBody1278=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1279=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1280=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1281=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1282=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1283=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1284=== CONT TestReadProxyNarinfo12852026/10/01 13:01:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12862026/10/01 13:01:44 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1287--- PASS: TestCompleteMultipartUnregistered (1.45s)1288=== CONT TestCreatePin_ReservedPins12892026/10/01 13:01:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50123/oidc12902026/10/01 13:01:44 INFO Received uploads request method=POST path=/api/pending_closures1291--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.68s)1292=== CONT TestOrphanedObjectsGCStressTest1293=== NAME TestPinProtectsFromGC1294 client_integration_test.go:840: Pin successfully protected closure from garbage collection1295--- PASS: TestPinProtectsFromGC (7.11s)1296=== CONT TestIsValidCachePath1297=== RUN TestIsValidCachePath/narinfo1298=== PAUSE TestIsValidCachePath/narinfo1299=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1300=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1301=== RUN TestIsValidCachePath/nar_zst1302=== PAUSE TestIsValidCachePath/nar_zst1303=== RUN TestIsValidCachePath/nar_xz1304=== PAUSE TestIsValidCachePath/nar_xz1305=== RUN TestIsValidCachePath/nar_bz21306=== PAUSE TestIsValidCachePath/nar_bz21307=== RUN TestIsValidCachePath/nar_uncompressed1308=== PAUSE TestIsValidCachePath/nar_uncompressed1309=== RUN TestIsValidCachePath/ls1310=== PAUSE TestIsValidCachePath/ls1311=== RUN TestIsValidCachePath/log1312=== PAUSE TestIsValidCachePath/log1313=== RUN TestIsValidCachePath/realisation1314=== PAUSE TestIsValidCachePath/realisation1315=== RUN TestIsValidCachePath/nix-cache-info1316=== PAUSE TestIsValidCachePath/nix-cache-info1317=== RUN TestIsValidCachePath/index.html1318=== PAUSE TestIsValidCachePath/index.html1319=== RUN TestIsValidCachePath/traversal_parent1320=== PAUSE TestIsValidCachePath/traversal_parent1321=== RUN TestIsValidCachePath/traversal_in_middle1322=== PAUSE TestIsValidCachePath/traversal_in_middle1323=== RUN TestIsValidCachePath/invalid_char_e1324=== PAUSE TestIsValidCachePath/invalid_char_e1325=== RUN TestIsValidCachePath/invalid_char_u1326=== PAUSE TestIsValidCachePath/invalid_char_u1327=== RUN TestIsValidCachePath/random_path1328=== PAUSE TestIsValidCachePath/random_path1329=== RUN TestIsValidCachePath/empty1330=== PAUSE TestIsValidCachePath/empty1331=== RUN TestIsValidCachePath/leading_slash1332=== PAUSE TestIsValidCachePath/leading_slash1333=== RUN TestIsValidCachePath/wrong_extension1334=== PAUSE TestIsValidCachePath/wrong_extension1335=== RUN TestIsValidCachePath/short_hash1336=== PAUSE TestIsValidCachePath/short_hash1337=== CONT TestOrphanedObjectsGC1338--- PASS: TestReadProxyNarStreaming (1.43s)1339=== CONT TestProxyHeadersOnlyTrustedOnSocket13402026/10/01 13:01:45 INFO Received uploads request method=POST path=/api/pending_closures13412026/10/01 13:01:45 INFO Received uploads request method=POST path=/api/pending_closures13422026/10/01 13:01:45 INFO Received uploads request method=POST path=/api/pending_closures13432026/10/01 13:01:45 INFO Received uploads request method=POST path=/api/pending_closures1344--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.81s)1345=== CONT TestObjectStatsTrigger13462026/10/01 13:01:46 INFO Received cleanup request method=DELETE path=/api/pending_closures13472026/10/01 13:01:46 INFO Aborted multipart uploads count=0 kept=013482026/10/01 13:01:46 INFO Received uploads request method=POST path=/api/pending_closures13492026/10/01 13:01:46 INFO Received cleanup request method=DELETE path=/api/pending_closures13502026/10/01 13:01:46 INFO Aborted multipart uploads count=1 kept=013512026/10/01 13:01:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13522026-10-01 13:01:46.351 UTC [14833] ERROR: Closure does not exist: id=113532026-10-01 13:01:46.351 UTC [14833] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13542026-10-01 13:01:46.351 UTC [14833] STATEMENT: -- name: CommitPendingClosure :exec1355 SELECT commit_pending_closure($1::bigint)1356 1357--- PASS: TestService_cleanupPendingClosuresHandler (2.03s)1358=== CONT TestParseSingleRange1359=== RUN TestParseSingleRange/none1360=== PAUSE TestParseSingleRange/none1361=== RUN TestParseSingleRange/unknown_unit1362=== PAUSE TestParseSingleRange/unknown_unit1363=== RUN TestParseSingleRange/multi-range_ignored1364=== PAUSE TestParseSingleRange/multi-range_ignored1365=== RUN TestParseSingleRange/malformed_no_dash1366=== PAUSE TestParseSingleRange/malformed_no_dash1367=== RUN TestParseSingleRange/malformed_both_empty1368=== PAUSE TestParseSingleRange/malformed_both_empty1369=== RUN TestParseSingleRange/malformed_end_before_start1370=== PAUSE TestParseSingleRange/malformed_end_before_start1371=== RUN TestParseSingleRange/closed1372=== PAUSE TestParseSingleRange/closed1373=== RUN TestParseSingleRange/open-ended1374=== PAUSE TestParseSingleRange/open-ended1375=== RUN TestParseSingleRange/end_clamped_to_size1376=== PAUSE TestParseSingleRange/end_clamped_to_size1377=== RUN TestParseSingleRange/suffix1378=== PAUSE TestParseSingleRange/suffix1379=== RUN TestParseSingleRange/suffix_exceeds_size1380=== PAUSE TestParseSingleRange/suffix_exceeds_size1381=== RUN TestParseSingleRange/single_byte1382=== PAUSE TestParseSingleRange/single_byte1383=== RUN TestParseSingleRange/start_past_EOF1384=== PAUSE TestParseSingleRange/start_past_EOF1385=== RUN TestParseSingleRange/start_far_past_EOF1386=== PAUSE TestParseSingleRange/start_far_past_EOF1387=== CONT TestPendingCleanupUsesOneCutoff13882026/10/01 13:01:46 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"13892026/10/01 13:01:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13902026/10/01 13:01:46 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LmQ5YTJmMWViLWZjMTgtNGVjMS1iNWJkLTRhMDE1Y2ZmMTE5MXgxNzkwODU5NzA1Mzg4OTEwMDAw parts=1013912026/10/01 13:01:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13922026/10/01 13:01:46 INFO Completed upload id=113932026/10/01 13:01:46 INFO Received uploads request method=POST path=/api/pending_closures13942026/10/01 13:01:46 INFO Received uploads request method=POST path=/api/pending_closures13952026/10/01 13:01:46 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13962026/10/01 13:01:46 WARN Found objects in DB but missing from S3, will re-upload count=11397--- PASS: TestService_verifyS3Integrity (3.05s)1398=== CONT TestPresentNotReportedWhileGCDeletesClosure13992026/10/01 13:01:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14002026/10/01 13:01:47 WARN Refused reserved pin name=worker-x86_64-linux14012026/10/01 13:01:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14022026/10/01 13:01:47 INFO Received create pin request method=POST path=/api/pins/my-app14032026/10/01 13:01:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1404--- PASS: TestCreatePin_ReservedPins (2.45s)1405=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14062026/10/01 13:01:47 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161407--- PASS: TestReadProxyNarinfo (2.61s)1408=== CONT TestPresentReportsOnlyClosureRoots14092026/10/01 13:01:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14102026/10/01 13:01:47 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjU1NTg5N2EtNjI5OS00YmZiLWE4NGEtYjE4NjhkYmMxYjI0LmM4MTkxZTQ3LTgyYmQtNGQyZC1hN2VkLTNiNTVjMzk5ODlmN3gxNzkwODU5NzA1NjM1ODExMDAw parts=1014112026/10/01 13:01:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14122026/10/01 13:01:47 INFO Completed upload id=114132026/10/01 13:01:47 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014142026/10/01 13:01:47 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/01 13:01:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures14162026/10/01 13:01:47 INFO Aborted multipart uploads count=0 kept=014172026/10/01 13:01:47 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=014182026/10/01 13:01:47 INFO Vacuumed table table=pending_closures14192026/10/01 13:01:47 INFO Vacuumed table table=pending_objects14202026/10/01 13:01:47 INFO Vacuumed table table=multipart_uploads14212026/10/01 13:01:47 INFO Vacuumed table table=closures14222026/10/01 13:01:47 INFO Vacuumed table table=objects14232026/10/01 13:01:47 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001424--- PASS: TestService_createPendingClosureHandler (3.35s)1425=== CONT TestGracefulShutdownDrainsInflight14262026/10/01 13:01:47 INFO Starting HTTP server address=127.0.0.1:5016214272026/10/01 13:01:47 INFO Shutdown signal received, draining in-flight requests timeout=10s1428--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1429=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1430--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.83s)1431=== CONT TestServerTLSConfig1432=== RUN TestServerTLSConfig/no_client_CA1433=== PAUSE TestServerTLSConfig/no_client_CA1434=== RUN TestServerTLSConfig/missing_CA_file1435=== PAUSE TestServerTLSConfig/missing_CA_file1436=== RUN TestServerTLSConfig/not_a_PEM_file1437=== PAUSE TestServerTLSConfig/not_a_PEM_file1438=== CONT TestService_NativeMTLS14392026/10/01 13:01:47 INFO Starting HTTP server address=/nix/var/nix/builds/nix-14421-1556620820/TestProxyHeadersOnlyTrustedOnSocket761407267/001/proxy.sock14402026/10/01 13:01:47 INFO Starting HTTP server address=127.0.0.1:5016714412026/10/01 13:01:47 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14422026/10/01 13:01:47 INFO Shutdown signal received, draining in-flight requests timeout=10s1443--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.71s)1444=== CONT TestGCTaskStore_GetEmpty1445--- PASS: TestGCTaskStore_GetEmpty (0.00s)1446=== CONT TestMetricsInventory1447=== NAME TestOrphanedObjectsGC1448 orphaned_objects_gc_test.go:290: GC Test Summary:1449 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1450 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1451 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1452 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1453 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1454--- PASS: TestOrphanedObjectsGC (3.23s)1455=== CONT TestGCTaskStore_Fail1456--- PASS: TestGCTaskStore_Fail (0.00s)1457=== CONT TestNARDeduplicationMetadataUploadBug1458--- PASS: TestObjectStatsTrigger (2.47s)1459=== CONT TestGCTaskStore_PhaseUpdates1460--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1461=== CONT TestCreatePendingClosureRejectsOversizedNAR14622026/10/01 13:01:48 INFO Received uploads request method=POST path=/api/pending_closures1463--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1464=== CONT TestGCTaskStore_CompletedAllowsNewTask1465--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1466=== CONT TestCacheConfigHandlerMaxNarSize1467--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1468=== CONT TestGCTaskStore_GetReturnsLatest1469--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1470=== CONT TestGenerateLandingPage1471--- PASS: TestGenerateLandingPage (0.00s)1472=== CONT TestService_readinessHandler14732026/10/01 13:01:48 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/01 13:01:48 INFO Received uploads request method=POST path=/api/pending_closures14752026/10/01 13:01:48 INFO Received cleanup request method=DELETE path=/api/pending_closures14762026/10/01 13:01:49 INFO Received uploads request method=POST path=/api/pending_closures1477--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.52s)1478=== CONT TestService_healthCheckHandler1479--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.84s)1480=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1481--- PASS: TestPresentReportsOnlyClosureRoots (2.70s)1482=== CONT TestIsValidUploadKey1483=== RUN TestIsValidUploadKey/narinfo1484=== PAUSE TestIsValidUploadKey/narinfo1485=== RUN TestIsValidUploadKey/nar_zst1486=== PAUSE TestIsValidUploadKey/nar_zst1487=== RUN TestIsValidUploadKey/nar_xz1488=== PAUSE TestIsValidUploadKey/nar_xz1489=== RUN TestIsValidUploadKey/nar_plain1490=== PAUSE TestIsValidUploadKey/nar_plain1491=== RUN TestIsValidUploadKey/listing1492=== PAUSE TestIsValidUploadKey/listing1493=== RUN TestIsValidUploadKey/build_log1494=== PAUSE TestIsValidUploadKey/build_log1495=== RUN TestIsValidUploadKey/build_log_home-manager_file1496=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1497=== RUN TestIsValidUploadKey/build_log_plus_in_name1498=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1499=== RUN TestIsValidUploadKey/build_log_question_mark1500=== PAUSE TestIsValidUploadKey/build_log_question_mark1501=== RUN TestIsValidUploadKey/build_log_equals1502=== PAUSE TestIsValidUploadKey/build_log_equals1503=== RUN TestIsValidUploadKey/realisation1504=== PAUSE TestIsValidUploadKey/realisation1505=== RUN TestIsValidUploadKey/realisation_plus_in_output1506=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1507=== RUN TestIsValidUploadKey/nix-cache-info1508=== PAUSE TestIsValidUploadKey/nix-cache-info1509=== RUN TestIsValidUploadKey/index.html1510=== PAUSE TestIsValidUploadKey/index.html1511=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1512=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1513=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1514=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1515=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1516=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1517=== RUN TestIsValidUploadKey/traversal1518=== PAUSE TestIsValidUploadKey/traversal1519=== RUN TestIsValidUploadKey/traversal_nar1520=== PAUSE TestIsValidUploadKey/traversal_nar1521=== RUN TestIsValidUploadKey/absolute1522=== PAUSE TestIsValidUploadKey/absolute1523=== RUN TestIsValidUploadKey/empty_key1524=== PAUSE TestIsValidUploadKey/empty_key1525=== RUN TestIsValidUploadKey/unknown_type1526=== PAUSE TestIsValidUploadKey/unknown_type1527=== CONT TestPendingClosureWriteTimeout1528=== RUN TestPendingClosureWriteTimeout/empty1529=== PAUSE TestPendingClosureWriteTimeout/empty1530=== RUN TestPendingClosureWriteTimeout/400_objects1531=== PAUSE TestPendingClosureWriteTimeout/400_objects1532=== RUN TestPendingClosureWriteTimeout/670k_objects1533=== PAUSE TestPendingClosureWriteTimeout/670k_objects1534=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1535=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1536=== CONT TestProxyWriteTimeout1537=== RUN TestProxyWriteTimeout/narinfo1538=== PAUSE TestProxyWriteTimeout/narinfo1539=== RUN TestProxyWriteTimeout/1_GiB_nar1540=== PAUSE TestProxyWriteTimeout/1_GiB_nar1541=== RUN TestProxyWriteTimeout/10_GiB_nar1542=== PAUSE TestProxyWriteTimeout/10_GiB_nar1543=== RUN TestProxyWriteTimeout/unknown_size1544=== PAUSE TestProxyWriteTimeout/unknown_size1545=== CONT TestParseSize1546--- PASS: TestParseSize (0.00s)1547=== CONT TestGCTaskStore_DeduplicateSameParams1548--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1549=== CONT TestSkippedUploadsHandler15502026/10/01 13:01:49 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001551--- PASS: TestSkippedUploadsHandler (0.00s)1552=== CONT TestGCTaskStore_ConflictDifferentParams1553--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1554=== CONT TestService_Rustfstest15552026/10/01 13:01:50 INFO Received push request method=POST path=/api/pushes15562026/10/01 13:01:50 INFO Received complete push request method=POST path=/api/pushes/1/complete15572026/10/01 13:01:50 INFO Received push request method=POST path=/api/pushes15582026/10/01 13:01:50 INFO Aborted multipart uploads count=0 kept=015592026/10/01 13:01:50 WARN Force mode enabled - objects will be deleted immediately without grace period15602026/10/01 13:01:50 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=015612026/10/01 13:01:50 INFO Vacuumed table table=pending_closures15622026/10/01 13:01:50 INFO Vacuumed table table=pending_objects15632026/10/01 13:01:50 INFO Vacuumed table table=multipart_uploads15642026/10/01 13:01:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15652026/10/01 13:01:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1566--- PASS: TestService_NativeMTLS (2.93s)1567=== CONT TestGCTaskStore_StartNew1568--- PASS: TestGCTaskStore_StartNew (0.00s)1569=== CONT TestGCEndsOnShutdown15702026/10/01 13:01:50 INFO Vacuumed table table=closures15712026/10/01 13:01:50 INFO Vacuumed table table=objects15722026/10/01 13:01:50 INFO Received complete push request method=POST path=/api/pushes/2/complete1573--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.18s)1574=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1575--- PASS: TestMetricsInventory (3.21s)1576=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15772026/10/01 13:01:51 WARN readiness check failed error="closed pool"1578--- PASS: TestService_readinessHandler (3.38s)1579=== CONT TestResolveDBConnectionString/flag_wins1580=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1581=== CONT TestResolveDBConnectionString/nothing_configured1582=== CONT TestResolveDBConnectionString/missing_file_is_an_error1583=== CONT TestResolveDBConnectionString/file_when_flag_empty1584=== CONT TestClientErrorHandling/InvalidStorePath1585--- PASS: TestResolveDBConnectionString (0.03s)1586 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1587 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1588 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1589 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1590 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1591=== NAME TestNARDeduplicationMetadataUploadBug1592 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-14421-1556620820/TestNARDeduplicationMetadataUploadBug4286215909/001/store/g6925jvr2d2hhxwkrbbah912alldpaki-file1.txt15932026/10/01 13:01:51 INFO Received push request method=POST path=/api/pushes15942026/10/01 13:01:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15952026/10/01 13:01:52 INFO Uploading g6925jvr2d2hhxwkrbbah912alldpaki-file1.txt (160B)15962026/10/01 13:01:52 WARN Failed to register uploaded object key=g6925jvr2d2hhxwkrbbah912alldpaki.ls error="server returned 404: 404 page not found\n"15972026/10/01 13:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15982026/10/01 13:01:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15992026/10/01 13:01:52 INFO Signed narinfos id=1 count=116002026/10/01 13:01:52 INFO Uploading 1 narinfos16012026/10/01 13:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete16022026/10/01 13:01:52 WARN Failed to register uploaded object key=g6925jvr2d2hhxwkrbbah912alldpaki.narinfo error="server returned 404: 404 page not found\n"16032026/10/01 13:01:52 INFO Upload complete. (214ms)1604 metadata_upload_test.go:54: Retrieved narinfo from S3:1605 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestNARDeduplicationMetadataUploadBug4286215909/001/store/g6925jvr2d2hhxwkrbbah912alldpaki-file1.txt1606 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1607 Compression: zstd1608 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1609 NarSize: 1601610 References: 1611 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1612 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1613 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1614 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1615 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-14421-1556620820/TestNARDeduplicationMetadataUploadBug4286215909/001/store/prgaxfmvf6a4xf9cfbwjg4kqrx8yvw23-file2.txt16162026/10/01 13:01:52 INFO Received push request method=POST path=/api/pushes16172026/10/01 13:01:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16182026/10/01 13:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16192026/10/01 13:01:52 INFO Signed narinfos id=2 count=116202026/10/01 13:01:52 INFO Uploading 1 narinfos16212026/10/01 13:01:52 WARN Failed to register uploaded object key=prgaxfmvf6a4xf9cfbwjg4kqrx8yvw23.ls error="server returned 404: 404 page not found\n"16222026/10/01 13:01:52 INFO Received complete push request method=POST path=/api/pushes/2/complete16232026/10/01 13:01:52 WARN Failed to register uploaded object key=prgaxfmvf6a4xf9cfbwjg4kqrx8yvw23.narinfo error="server returned 404: 404 page not found\n"16242026/10/01 13:01:52 INFO Upload complete. (100ms)1625 metadata_upload_test.go:76: Retrieved narinfo from S3:1626 StorePath: /nix/var/nix/builds/nix-14421-1556620820/TestNARDeduplicationMetadataUploadBug4286215909/001/store/prgaxfmvf6a4xf9cfbwjg4kqrx8yvw23-file2.txt1627 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1628 Compression: zstd1629 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1630 NarSize: 1601631 References: 1632 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1633 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1634 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1635 {"version":1,"root":{"type":"regular","size":44}}1636--- PASS: TestNARDeduplicationMetadataUploadBug (4.03s)1637=== CONT TestClientErrorHandling/ServerNotAvailable16382026/10/01 13:01:52 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/present1639--- PASS: TestService_healthCheckHandler (3.06s)1640=== CONT TestClientErrorHandling/InvalidAuthToken16412026/10/01 13:01:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.249137ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16422026/10/01 13:01:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=420.505429ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16432026/10/01 13:01:53 INFO Received uploads request method=POST path=/api/pending_closures1644=== NAME TestOrphanedObjectsGCStressTest1645 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1646 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16472026/10/01 13:01:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.097115ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1648--- PASS: TestService_Rustfstest (3.50s)1649=== CONT TestCacheConfigHandler/full_config,_no_issuer1650=== CONT TestCacheConfigHandler/no_signing_keys1651=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1652=== CONT TestCacheConfigHandler/no_cache_url_configured1653--- PASS: TestCacheConfigHandler (0.00s)1654 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1655 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1656 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1657 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1658=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1659=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16602026/10/01 13:01: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]1661=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1662=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16632026/10/01 13:01:53 WARN Authentication failed token_preview=eyJhbGciOi...YXFBtd9S0Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1664=== CONT TestService_RequireScope_OIDC/builder_may_write1665=== CONT TestService_RequireScope_OIDC/static_token_may_admin1666=== CONT TestService_RequireScope_OIDC/reader_may_not_write1667=== CONT TestService_RequireScope_OIDC/ops_may_not_write1668=== CONT TestService_RequireScope_OIDC/ops_may_admin1669=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1670=== CONT TestService_RequireScope_OIDC/static_token_may_write1671=== CONT TestService_RequireScope_OIDC/writer_implies_read1672=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1673=== CONT TestService_RequireScope_OIDC/reader_may_read1674=== CONT TestPush_RejectsBadRequests/no_roots16752026/10/01 13:01:53 INFO Received push request method=POST path=/api/pushes1676=== CONT TestPush_RejectsBadRequests/bad_root16772026/10/01 13:01:53 INFO Received push request method=POST path=/api/pushes1678=== CONT TestPush_RejectsBadRequests/root_not_in_objects16792026/10/01 13:01:53 INFO Received push request method=POST path=/api/pushes1680=== CONT TestPush_RejectsBadRequests/no_objects16812026/10/01 13:01:53 INFO Received push request method=POST path=/api/pushes1682=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1683--- PASS: TestPush_RejectsBadRequests (1.24s)1684 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1685 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1686 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1687 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)16882026/10/01 13:01:53 INFO Received uploads request method=POST path=/1689=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16902026/10/01 13:01:53 INFO Received complete multipart upload request method=POST path=/1691=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16922026/10/01 13:01:53 INFO Received request for more parts method=POST path=/1693=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16942026/10/01 13:01:53 INFO Received uploads request method=POST path=/1695--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1696 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1697 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1698 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1699 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1700=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17012026/10/01 13:01:53 INFO Received request for more parts method=POST path=/1702--- PASS: TestService_AuthMiddleware_OIDC (1.14s)1703 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1704 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1705 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1706 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1707--- PASS: TestService_RequireScope_OIDC (1.19s)1708 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1709 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1710 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1711 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1712 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1713 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1714 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1715 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1716 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1717 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1718=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17192026/10/01 13:01:53 INFO Received complete multipart upload request method=POST path=/17202026/10/01 13:01:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1721=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17222026/10/01 13:01:53 INFO Received uploads request method=POST path=/1723--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1724 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1725 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1726 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)1727=== CONT TestIsValidCachePath/narinfo1728=== CONT TestIsValidCachePath/index.html1729=== CONT TestIsValidCachePath/nar_uncompressed1730=== CONT TestIsValidCachePath/short_hash1731=== CONT TestIsValidCachePath/invalid_char_u1732=== CONT TestIsValidCachePath/nix-cache-info1733=== CONT TestIsValidCachePath/random_path1734=== CONT TestIsValidCachePath/realisation1735=== CONT TestIsValidCachePath/invalid_char_e1736=== CONT TestIsValidCachePath/wrong_extension1737=== CONT TestIsValidCachePath/traversal_in_middle1738=== CONT TestIsValidCachePath/leading_slash1739=== CONT TestIsValidCachePath/log1740=== CONT TestIsValidCachePath/traversal_parent1741=== CONT TestIsValidCachePath/empty1742=== CONT TestIsValidCachePath/ls1743=== CONT TestIsValidCachePath/nar_xz1744=== CONT TestIsValidCachePath/nar_zst1745=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1746=== CONT TestIsValidCachePath/nar_bz21747--- PASS: TestIsValidCachePath (0.00s)1748 --- PASS: TestIsValidCachePath/narinfo (0.00s)1749 --- PASS: TestIsValidCachePath/index.html (0.00s)1750 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1751 --- PASS: TestIsValidCachePath/short_hash (0.00s)1752 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1753 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1754 --- PASS: TestIsValidCachePath/random_path (0.00s)1755 --- PASS: TestIsValidCachePath/realisation (0.00s)1756 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1757 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1758 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1759 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1760 --- PASS: TestIsValidCachePath/log (0.00s)1761 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1762 --- PASS: TestIsValidCachePath/empty (0.00s)1763 --- PASS: TestIsValidCachePath/ls (0.00s)1764 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1765 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1766 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1767 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1768=== CONT TestParseSingleRange/none1769=== CONT TestParseSingleRange/open-ended1770=== CONT TestParseSingleRange/start_far_past_EOF1771=== CONT TestParseSingleRange/start_past_EOF1772=== CONT TestParseSingleRange/single_byte1773=== CONT TestParseSingleRange/suffix_exceeds_size1774=== CONT TestParseSingleRange/suffix1775=== CONT TestParseSingleRange/end_clamped_to_size1776=== CONT TestParseSingleRange/malformed_both_empty1777=== CONT TestParseSingleRange/closed1778=== CONT TestParseSingleRange/malformed_end_before_start1779=== CONT TestParseSingleRange/multi-range_ignored1780=== CONT TestParseSingleRange/malformed_no_dash1781=== CONT TestParseSingleRange/unknown_unit1782--- PASS: TestParseSingleRange (0.00s)1783 --- PASS: TestParseSingleRange/none (0.00s)1784 --- PASS: TestParseSingleRange/open-ended (0.00s)1785 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1786 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1787 --- PASS: TestParseSingleRange/single_byte (0.00s)1788 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1789 --- PASS: TestParseSingleRange/suffix (0.00s)1790 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1791 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1792 --- PASS: TestParseSingleRange/closed (0.00s)1793 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1794 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1795 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1796 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1797=== CONT TestServerTLSConfig/no_client_CA1798=== CONT TestServerTLSConfig/not_a_PEM_file1799=== CONT TestServerTLSConfig/missing_CA_file1800--- PASS: TestServerTLSConfig (0.00s)1801 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1802 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1803 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1804=== CONT TestIsValidUploadKey/narinfo1805=== CONT TestIsValidUploadKey/empty_key1806=== CONT TestIsValidUploadKey/absolute1807=== CONT TestIsValidUploadKey/traversal_nar1808=== CONT TestIsValidUploadKey/traversal1809=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1810=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1811=== CONT TestIsValidUploadKey/unknown_type1812=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1813=== CONT TestIsValidUploadKey/index.html1814=== CONT TestIsValidUploadKey/nix-cache-info1815=== CONT TestIsValidUploadKey/realisation_plus_in_output1816=== CONT TestIsValidUploadKey/realisation1817=== CONT TestIsValidUploadKey/build_log_equals1818=== CONT TestIsValidUploadKey/build_log_question_mark1819=== CONT TestIsValidUploadKey/build_log_plus_in_name1820=== CONT TestIsValidUploadKey/build_log_home-manager_file1821=== CONT TestIsValidUploadKey/build_log1822=== CONT TestIsValidUploadKey/listing1823=== CONT TestIsValidUploadKey/nar_plain1824=== CONT TestIsValidUploadKey/nar_xz1825=== CONT TestIsValidUploadKey/nar_zst1826--- PASS: TestIsValidUploadKey (0.00s)1827 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1828 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1829 --- PASS: TestIsValidUploadKey/absolute (0.00s)1830 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1831 --- PASS: TestIsValidUploadKey/traversal (0.00s)1832 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1833 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1834 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1835 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1836 --- PASS: TestIsValidUploadKey/index.html (0.00s)1837 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1838 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1839 --- PASS: TestIsValidUploadKey/realisation (0.00s)1840 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1841 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1842 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1843 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1844 --- PASS: TestIsValidUploadKey/build_log (0.00s)1845 --- PASS: TestIsValidUploadKey/listing (0.00s)1846 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1847 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1848 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1849=== CONT TestPendingClosureWriteTimeout/empty1850=== CONT TestPendingClosureWriteTimeout/670k_objects1851=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1852--- PASS: TestGCEndsOnShutdown (3.16s)1853=== CONT TestPendingClosureWriteTimeout/400_objects1854=== CONT TestProxyWriteTimeout/narinfo1855=== CONT TestProxyWriteTimeout/10_GiB_nar1856=== CONT TestProxyWriteTimeout/unknown_size1857=== CONT TestProxyWriteTimeout/1_GiB_nar1858--- PASS: TestProxyWriteTimeout (0.00s)1859 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1860 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1861 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1862 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)18632026/10/01 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures18642026/10/01 13:01:54 INFO Aborted multipart uploads count=0 kept=018652026/10/01 13:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period18662026/10/01 13:01:54 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=018672026/10/01 13:01:54 INFO Vacuumed table table=pending_closures18682026/10/01 13:01:54 INFO Vacuumed table table=pending_objects18692026/10/01 13:01:54 INFO Vacuumed table table=multipart_uploads18702026/10/01 13:01:54 INFO Vacuumed table table=closures18712026/10/01 13:01:54 INFO Vacuumed table table=objects18722026/10/01 13:01:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.650892609s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18732026/10/01 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures18742026/10/01 13:01:54 INFO Aborted multipart uploads count=0 kept=018752026/10/01 13:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period18762026/10/01 13:01: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=018772026/10/01 13:01:54 INFO Vacuumed table table=pending_closures18782026/10/01 13:01:54 INFO Vacuumed table table=pending_objects18792026/10/01 13:01:54 INFO Vacuumed table table=multipart_uploads18802026/10/01 13:01:54 INFO Vacuumed table table=closures18812026/10/01 13:01:54 INFO Vacuumed table table=objects1882--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1883 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.64s)1884 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.50s)18852026/10/01 13:01:54 INFO Aborted multipart uploads count=1 kept=018862026/10/01 13:01:54 INFO Received cleanup request method=DELETE path=/api/pending_closures18872026/10/01 13:01:54 INFO Aborted multipart uploads count=1 kept=01888--- PASS: TestPendingCleanupUsesOneCutoff (8.43s)18892026/10/01 13:01:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18902026/10/01 13:01:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1891=== NAME TestOrphanedObjectsGCStressTest1892 orphaned_objects_gc_test.go:509: Stress test completed successfully:1893 orphaned_objects_gc_test.go:510: - Active objects preserved: 201894 orphaned_objects_gc_test.go:511: - Objects deleted: 2101895 orphaned_objects_gc_test.go:512: - Total GC'd: 2101896--- PASS: TestOrphanedObjectsGCStressTest (10.49s)18972026/10/01 13:01:55 INFO Received uploads request method=POST path=/api/pending_closures18982026/10/01 13:01:55 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-config18992026/10/01 13:01:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.525884ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1900--- PASS: TestPendingClosureWriteTimeout (0.00s)1901 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1902 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1903 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1904 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.45s)19052026/10/01 13:01:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.038049ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19062026/10/01 13:01:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=870.123132ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19072026/10/01 13:01:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.57136007s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/10/01 13:01:58 WARN Rate limiter enabled after throttle name=s3-test rate=519092026/10/01 13:01:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1910=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1911 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101912 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001913--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.19s)19142026/10/01 13:01: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:01: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:01:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.892427ms 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:01:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.081531ms 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:01:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.227621ms 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:02:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.461322418s 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:02: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:02:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.671142ms 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:02:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.008384ms 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:02:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=828.383049ms 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:02:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.719314403s 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 (3.00s)1927 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.63s)1928 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.05s)1929PASS1930{"timestamp":"2026-10-01T13:02:05.424422Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50156","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}19312026-10-01 13:02:05.553 UTC [14473] LOG: received smart shutdown request19322026-10-01 13:02:05.554 UTC [14473] LOG: background worker "logical replication launcher" (PID 14483) exited with exit code 119332026-10-01 13:02:05.561 UTC [14478] LOG: shutting down19342026-10-01 13:02:05.561 UTC [14478] LOG: checkpoint starting: shutdown immediate19352026-10-01 13:02:06.817 UTC [14478] LOG: checkpoint complete: wrote 12679 buffers (77.4%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.719 s, sync=0.509 s, total=1.256 s; sync files=29991, longest=0.001 s, average=0.001 s; distance=421752 kB, estimate=421752 kB; lsn=0/1B36B230, redo lsn=0/1B36B23019362026-10-01 13:02:06.822 UTC [14473] LOG: database system is shut down1937Running OIDC tests...1938=== RUN TestAudienceForIssuer1939=== PAUSE TestAudienceForIssuer1940=== RUN TestGlobMatch1941=== PAUSE TestGlobMatch1942=== RUN TestValidateToken_ValidToken1943=== PAUSE TestValidateToken_ValidToken1944=== RUN TestValidateToken_WrongAudience1945=== PAUSE TestValidateToken_WrongAudience1946=== RUN TestValidateToken_Expired1947=== PAUSE TestValidateToken_Expired1948=== RUN TestValidateToken_BoundClaimsMismatch1949=== PAUSE TestValidateToken_BoundClaimsMismatch1950=== RUN TestValidateToken_BoundSubjectMismatch1951=== PAUSE TestValidateToken_BoundSubjectMismatch1952=== RUN TestValidateToken_MultipleProviders1953=== PAUSE TestValidateToken_MultipleProviders1954=== RUN TestValidateToken_NoMatchingProvider1955=== PAUSE TestValidateToken_NoMatchingProvider1956=== RUN TestValidateToken_KubernetesServiceAccount1957=== PAUSE TestValidateToken_KubernetesServiceAccount1958=== RUN TestNewValidator_KubernetesRequiresCA1959=== PAUSE TestNewValidator_KubernetesRequiresCA1960=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1961=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1962=== RUN TestPins_ReservedForMatchingRule1963=== PAUSE TestPins_ReservedForMatchingRule1964=== RUN TestPins_TopLevelShorthand1965=== PAUSE TestPins_TopLevelShorthand1966=== RUN TestPins_ConfigValidation1967=== PAUSE TestPins_ConfigValidation1968=== RUN TestScopes_LegacyProviderDefaultsToWrite1969=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1970=== RUN TestScopes_Rules1971=== PAUSE TestScopes_Rules1972=== RUN TestScopes_ConfigValidation1973=== PAUSE TestScopes_ConfigValidation1974=== CONT TestAudienceForIssuer1975--- PASS: TestAudienceForIssuer (0.00s)1976=== CONT TestValidateToken_NoMatchingProvider1977=== CONT TestValidateToken_KubernetesServiceAccount1978=== CONT TestValidateToken_BoundSubjectMismatch1979=== CONT TestValidateToken_ValidToken1980=== CONT TestGlobMatch1981=== RUN TestGlobMatch/foo_foo1982=== PAUSE TestGlobMatch/foo_foo1983=== RUN TestGlobMatch/foo_bar1984=== CONT TestValidateToken_WrongAudience1985=== CONT TestValidateToken_BoundClaimsMismatch1986=== CONT TestValidateToken_Expired1987=== PAUSE TestGlobMatch/foo_bar1988=== RUN TestGlobMatch/*_1989=== PAUSE TestGlobMatch/*_1990=== RUN TestGlobMatch/*_anything1991=== PAUSE TestGlobMatch/*_anything1992=== RUN TestGlobMatch/foo*_foo1993=== CONT TestPins_ConfigValidation1994=== CONT TestValidateToken_MultipleProviders1995=== PAUSE TestGlobMatch/foo*_foo1996=== RUN TestGlobMatch/foo*_foobar1997=== PAUSE TestGlobMatch/foo*_foobar1998=== RUN TestGlobMatch/foo*_bar1999=== PAUSE TestGlobMatch/foo*_bar2000=== RUN TestGlobMatch/*bar_bar2001=== PAUSE TestGlobMatch/*bar_bar2002=== RUN TestGlobMatch/*bar_foobar2003=== PAUSE TestGlobMatch/*bar_foobar2004=== RUN TestGlobMatch/*bar_foo2005=== PAUSE TestGlobMatch/*bar_foo2006=== RUN TestGlobMatch/foo*bar_foobar2007=== PAUSE TestGlobMatch/foo*bar_foobar2008=== RUN TestGlobMatch/foo*bar_foo123bar2009=== PAUSE TestGlobMatch/foo*bar_foo123bar2010=== RUN TestGlobMatch/foo*bar_foobarbaz2011=== PAUSE TestGlobMatch/foo*bar_foobarbaz2012=== RUN TestGlobMatch/*/*_foo/bar2013=== PAUSE TestGlobMatch/*/*_foo/bar2014=== RUN TestGlobMatch/*/*_foo2015=== PAUSE TestGlobMatch/*/*_foo2016=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2017=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2018=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02019=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02020=== RUN TestGlobMatch/refs/*/main_refs/heads/main2021=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2022=== RUN TestGlobMatch/fo?_foo2023=== PAUSE TestGlobMatch/fo?_foo2024=== RUN TestGlobMatch/fo?_fo2025=== PAUSE TestGlobMatch/fo?_fo2026=== RUN TestGlobMatch/fo?_fooo2027=== PAUSE TestGlobMatch/fo?_fooo2028=== RUN TestGlobMatch/?oo_foo2029=== PAUSE TestGlobMatch/?oo_foo2030=== RUN TestGlobMatch/?oo_boo2031=== PAUSE TestGlobMatch/?oo_boo2032=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2033=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2034=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2035=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2036=== CONT TestScopes_ConfigValidation2037--- PASS: TestPins_ConfigValidation (0.00s)2038=== CONT TestScopes_Rules2039--- PASS: TestScopes_ConfigValidation (0.00s)2040=== CONT TestScopes_LegacyProviderDefaultsToWrite20412026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50288/oidc20422026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50287/oidc2043--- PASS: TestValidateToken_WrongAudience (0.06s)2044=== CONT TestPins_ReservedForMatchingRule2045--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2046=== CONT TestPins_TopLevelShorthand20472026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50293/oidc2048--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2049=== CONT TestValidateToken_KubernetesIssuerFromOwnToken20502026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50295/oidc20512026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50297/oidc2052--- PASS: TestScopes_Rules (0.07s)2053=== CONT TestNewValidator_KubernetesRequiresCA2054--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)2055=== CONT TestGlobMatch/foo_foo2056=== 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/bar2068=== CONT TestGlobMatch/foo*bar_foobarbaz2069=== CONT TestGlobMatch/foo*bar_foo123bar2070=== CONT TestGlobMatch/foo*bar_foobar2071=== CONT TestGlobMatch/*bar_foo2072=== CONT TestGlobMatch/*bar_foobar2073=== CONT TestGlobMatch/*bar_bar2074=== CONT TestGlobMatch/foo*_bar2075=== CONT TestGlobMatch/foo*_foobar2076=== CONT TestGlobMatch/foo*_foo2077=== CONT TestGlobMatch/*_anything2078=== CONT TestGlobMatch/*_2079=== CONT TestGlobMatch/foo_bar2080--- PASS: TestGlobMatch (0.01s)2081 --- PASS: TestGlobMatch/foo_foo (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 (0.00s)2094 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2095 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2096 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2097 --- PASS: TestGlobMatch/*bar_foo (0.00s)2098 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2099 --- PASS: TestGlobMatch/*bar_bar (0.00s)2100 --- PASS: TestGlobMatch/foo*_bar (0.00s)2101 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2102 --- PASS: TestGlobMatch/foo*_foo (0.00s)2103 --- PASS: TestGlobMatch/*_anything (0.00s)2104 --- PASS: TestGlobMatch/*_ (0.00s)2105 --- PASS: TestGlobMatch/foo_bar (0.00s)21062026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50299/oidc2107--- PASS: TestPins_ReservedForMatchingRule (0.04s)21082026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50303/oidc21092026/10/01 13:02:08 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:503012110--- PASS: TestValidateToken_ValidToken (0.10s)2111--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)21122026/10/01 13:02:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50292/oidc2113--- PASS: TestValidateToken_NoMatchingProvider (0.11s)21142026/10/01 13:02:08 http: TLS handshake error from 127.0.0.1:50308: remote error: tls: bad certificate2115--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)21162026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50309/oidc2117--- PASS: TestValidateToken_Expired (0.11s)21182026/10/01 13:02:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50291/oidc21192026/10/01 13:02:08 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50311/oidc2120--- PASS: TestValidateToken_MultipleProviders (0.12s)21212026/10/01 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50314/oidc21222026/10/01 13:02:08 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232123--- PASS: TestPins_TopLevelShorthand (0.08s)2124--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)2125PASS2126Running hook tests...2127=== RUN TestSendPathsEmpty2128=== PAUSE TestSendPathsEmpty2129=== RUN TestQueueEnqueueAndFetch2130=== PAUSE TestQueueEnqueueAndFetch2131=== RUN TestQueueDeduplication2132=== PAUSE TestQueueDeduplication2133=== RUN TestQueueRemove2134=== PAUSE TestQueueRemove2135=== RUN TestQueueFetchBatchLimit2136=== PAUSE TestQueueFetchBatchLimit2137=== RUN TestQueueRetryMovesToBack2138=== PAUSE TestQueueRetryMovesToBack2139=== RUN TestQueueFetchRemoveLifecycle2140=== PAUSE TestQueueFetchRemoveLifecycle2141=== RUN TestQueueConcurrentWriters2142=== PAUSE TestQueueConcurrentWriters2143=== RUN TestQueueRemoveLargeClosure2144=== PAUSE TestQueueRemoveLargeClosure2145=== RUN TestServerClientIntegration2146=== PAUSE TestServerClientIntegration2147=== RUN TestServerQueueError2148=== PAUSE TestServerQueueError2149=== RUN TestGetListenerSocketActivation2150 server_test.go:210: === RUN TestGetListenerSocketActivation2151 --- PASS: TestGetListenerSocketActivation (0.00s)2152 PASS2153 2154--- PASS: TestGetListenerSocketActivation (0.01s)2155=== RUN TestDrainIsolatesPoisonPath2156=== PAUSE TestDrainIsolatesPoisonPath2157=== RUN TestRunNotBlockedByPoisonHead2158=== PAUSE TestRunNotBlockedByPoisonHead2159=== RUN TestDrainGivesUpWhenServerDown2160=== PAUSE TestDrainGivesUpWhenServerDown2161=== RUN TestFailedPathPrunedByLaterClosure2162=== PAUSE TestFailedPathPrunedByLaterClosure2163=== RUN TestWorkerUploadsAndRemoves2164=== PAUSE TestWorkerUploadsAndRemoves2165=== RUN TestWorkerSkipsGCdPaths2166=== PAUSE TestWorkerSkipsGCdPaths2167=== RUN TestWorkerPrunesClosureDeps2168=== PAUSE TestWorkerPrunesClosureDeps2169=== RUN TestDrainTimeout2170=== PAUSE TestDrainTimeout2171=== CONT TestSendPathsEmpty2172=== CONT TestServerQueueError2173=== CONT TestQueueDeduplication2174=== CONT TestQueueRetryMovesToBack2175=== CONT TestQueueEnqueueAndFetch2176=== CONT TestQueueFetchBatchLimit2177=== CONT TestQueueRemove2178=== CONT TestWorkerUploadsAndRemoves2179=== CONT TestDrainTimeout2180=== CONT TestWorkerPrunesClosureDeps2181=== CONT TestWorkerSkipsGCdPaths2182--- PASS: TestSendPathsEmpty (0.00s)21832026/10/01 13:02:08 ERROR Failed to queue paths error="permission denied" count=12184--- PASS: TestServerQueueError (0.00s)2185=== CONT TestQueueRemoveLargeClosure21862026/10/01 13:02:08 INFO Upload queue status pending=221872026/10/01 13:02:08 INFO Uploading batch count=221882026/10/01 13:02:08 INFO Upload queue status pending=221892026/10/01 13:02:08 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-14421-1556620820/TestWorkerSkipsGCdPaths1818404237/002/nonexistent2190--- PASS: TestQueueEnqueueAndFetch (0.01s)2191=== CONT TestServerClientIntegration21922026/10/01 13:02:08 INFO Upload queue status pending=221932026/10/01 13:02:08 INFO Uploading batch count=121942026/10/01 13:02:08 INFO Uploading batch count=221952026/10/01 13:02:08 INFO Uploading batch count=12196--- PASS: TestQueueFetchBatchLimit (0.01s)2197=== CONT TestDrainGivesUpWhenServerDown2198--- PASS: TestQueueDeduplication (0.01s)2199=== CONT TestFailedPathPrunedByLaterClosure2200--- PASS: TestQueueRetryMovesToBack (0.01s)2201=== CONT TestQueueConcurrentWriters2202--- PASS: TestServerClientIntegration (0.00s)2203=== CONT TestDrainIsolatesPoisonPath2204--- PASS: TestQueueRemove (0.01s)2205=== CONT TestRunNotBlockedByPoisonHead22062026/10/01 13:02:08 INFO Uploading batch count=122072026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=122082026/10/01 13:02:08 INFO Uploading batch count=122092026/10/01 13:02:08 INFO Uploading batch count=422102026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=422112026/10/01 13:02:08 INFO Upload queue status pending=322122026/10/01 13:02:08 INFO Uploading batch count=122132026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=122142026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainIsolatesPoisonPath988969205/002/bbb22152026/10/01 13:02:08 INFO Uploading batch count=122162026/10/01 13:02:08 INFO Uploading batch count=222172026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=222182026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/a22192026/10/01 13:02:08 INFO Uploading batch count=122202026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=122212026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/b22222026/10/01 13:02:08 INFO Uploading batch count=222232026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=222242026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/c22252026/10/01 13:02:08 INFO Uploading batch count=122262026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=122272026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/d22282026/10/01 13:02:08 INFO Uploading batch count=122292026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=122302026/10/01 13:02:08 INFO Uploading batch count=222312026/10/01 13:02:08 ERROR Upload failed error="upload failed" count=222322026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/e22332026/10/01 13:02:08 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14421-1556620820/TestDrainGivesUpWhenServerDown2389443520/002/f2234--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2235=== CONT TestQueueFetchRemoveLifecycle22362026/10/01 13:02:08 ERROR Drain finished with paths left in queue remaining=122372026/10/01 13:02:08 ERROR Drain finished with paths left in queue remaining=102238--- PASS: TestDrainIsolatesPoisonPath (0.01s)2239--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2240--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2241--- PASS: TestWorkerUploadsAndRemoves (0.03s)2242--- PASS: TestWorkerSkipsGCdPaths (0.03s)2243--- PASS: TestWorkerPrunesClosureDeps (0.03s)2244--- PASS: TestQueueRemoveLargeClosure (0.06s)2245--- PASS: TestQueueConcurrentWriters (0.14s)22462026/10/01 13:02:08 ERROR Upload failed error="context deadline exceeded" count=222472026/10/01 13:02:08 ERROR Drain finished with paths left in queue remaining=42248--- PASS: TestDrainTimeout (0.21s)22492026/10/01 13:02:09 INFO Uploading batch count=122502026/10/01 13:02:09 INFO Uploading batch count=122512026/10/01 13:02:09 INFO Uploading batch count=122522026/10/01 13:02:09 ERROR Upload failed error="upload failed" count=122532026/10/01 13:02:09 INFO Uploading batch count=122542026/10/01 13:02:09 ERROR Upload failed error="upload failed" count=122552026/10/01 13:02:09 INFO Uploading batch count=122562026/10/01 13:02:09 ERROR Upload failed error="upload failed" count=122572026/10/01 13:02:09 INFO Uploading batch count=122582026/10/01 13:02:09 ERROR Upload failed error="upload failed" count=122592026/10/01 13:02:09 ERROR Drain finished with paths left in queue remaining=12260--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2261PASS