niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #345
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestSetClientTLSErrors97=== CONT TestScriptTokenEmptyCommand98=== CONT TestFileTokenReadsAndCaches99=== CONT TestScriptTokenScriptFails100=== CONT TestScriptTokenBadJSON101=== CONT TestScriptTokenEmptyToken102=== CONT TestScriptTokenCachesUntilRefresh103=== CONT TestScriptTokenNoExpiryRerunsEveryCall104=== CONT TestStaticToken105=== CONT TestPathInfoCACompatibility106=== RUN TestPathInfoCACompatibility/null_ca_field107=== PAUSE TestPathInfoCACompatibility/null_ca_field108=== RUN TestPathInfoCACompatibility/old_string_format_-_text109=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text110=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive111=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive112=== RUN TestPathInfoCACompatibility/new_structured_format_-_text113=== CONT TestFileTokenEmpty114--- PASS: TestShellSplit (0.00s)115--- PASS: TestScriptTokenEmptyCommand (0.00s)116=== CONT TestFileTokenMissing117--- PASS: TestFileTokenReadsAndCaches (0.00s)118--- PASS: TestStaticToken (0.00s)119=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text120=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method121=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method122=== CONT TestDoWithRetry_BodyReplayedViaGetBody123--- PASS: TestFileTokenMissing (0.00s)124--- PASS: TestFileTokenEmpty (0.00s)125=== CONT TestResolveStorePath126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1272026/10/01 12:50:54 WARN Rate limiter enabled after throttle name=server-test rate=5128--- PASS: TestScriptTokenScriptFails (0.01s)129=== CONT TestRateLimiterFeedback130=== RUN TestRateLimiterFeedback/429_enables_limiter131=== PAUSE TestRateLimiterFeedback/429_enables_limiter132=== RUN TestRateLimiterFeedback/503_enables_limiter133=== PAUSE TestRateLimiterFeedback/503_enables_limiter134=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter135=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter1362026/10/01 12:50:54 WARN Rate limiter enabled after throttle name=server-test rate=51372026/10/01 12:50:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65492138=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter139=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter140=== CONT TestEncodeNixBase32WithRealHash141--- PASS: TestEncodeNixBase32WithRealHash (0.00s)142=== CONT TestParsePathInfoJSONMultiplePaths143=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths144=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths146=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths147=== CONT TestParsePathInfoJSON148=== RUN TestParsePathInfoJSON/Nix_format149=== PAUSE TestParsePathInfoJSON/Nix_format150=== RUN TestParsePathInfoJSON/Lix_format1512026/10/01 12:50:54 WARN Rate limiter backed off name=server-test rate=5152--- PASS: TestDoServerRequestAttachesToken (0.01s)1532026/10/01 12:50:54 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65492154=== CONT TestPathInfoHashCompatibility155=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon159=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI160=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI161=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512162=== PAUSE TestParsePathInfoJSON/Lix_format163=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512164=== RUN TestParsePathInfoJSON/empty_input165=== PAUSE TestParsePathInfoJSON/empty_input166=== RUN TestParsePathInfoJSON/whitespace_only167=== PAUSE TestParsePathInfoJSON/whitespace_only168=== RUN TestParsePathInfoJSON/invalid_JSON169=== CONT TestConvertHashToNix32170=== PAUSE TestParsePathInfoJSON/invalid_JSON171=== CONT TestGetStorePathHash172=== RUN TestGetStorePathHash/valid_store_path173--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)174=== RUN TestConvertHashToNix32/SRI_format_to_Nix32175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== RUN TestConvertHashToNix32/already_Nix32_format177=== PAUSE TestConvertHashToNix32/already_Nix32_format178=== RUN TestConvertHashToNix32/invalid_format179=== PAUSE TestConvertHashToNix32/invalid_format180=== CONT TestUploadMultipart_SupersededByPeer181--- PASS: TestResolveStorePath (0.00s)182=== CONT TestDumpPathWriterError183=== PAUSE TestGetStorePathHash/valid_store_path184=== RUN TestSetClientTLSErrors/missing_cert_file185=== PAUSE TestSetClientTLSErrors/missing_cert_file186=== RUN TestUploadMultipart_SupersededByPeer/exists187=== RUN TestGetStorePathHash/basename_without_hyphen_should_error188=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error189=== CONT TestEncodeNixBase32190=== RUN TestEncodeNixBase32/test_string_hash191=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error192=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error193=== RUN TestSetClientTLSErrors/missing_key_file194=== PAUSE TestSetClientTLSErrors/missing_key_file195=== PAUSE TestEncodeNixBase32/test_string_hash196=== RUN TestEncodeNixBase32/empty_input197=== PAUSE TestEncodeNixBase32/empty_input198=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error199=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error200=== CONT TestDumpPathSingleFile201=== CONT TestDumpPathMatchesNix202=== RUN TestSetClientTLSErrors/missing_ca_file203=== PAUSE TestSetClientTLSErrors/missing_ca_file204=== RUN TestSetClientTLSErrors/invalid_ca_file205=== PAUSE TestSetClientTLSErrors/invalid_ca_file206=== PAUSE TestUploadMultipart_SupersededByPeer/exists207=== RUN TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestUploadMultipart_SupersededByPeer/missing209=== CONT TestFilterOversizedClosures210=== RUN TestFilterOversizedClosures/no_limit_keeps_everything211=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything212=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped214=== RUN TestFilterOversizedClosures/all_closures_skipped215=== CONT TestCaseHackSuffix216=== PAUSE TestFilterOversizedClosures/all_closures_skipped217=== CONT TestPartSizeForNAR218=== RUN TestPartSizeForNAR/zero_stays_at_minimum219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum224=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts225=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts226=== RUN TestPartSizeForNAR/1_TiB227=== PAUSE TestPartSizeForNAR/1_TiB228=== RUN TestPartSizeForNAR/5_TiB_S3_max_object229=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object230=== RUN TestPartSizeForNAR/capped_at_5_GiB231=== PAUSE TestPartSizeForNAR/capped_at_5_GiB232=== CONT TestUploadMultipart_PartsInParallel233--- PASS: TestScriptTokenEmptyToken (0.01s)234=== CONT TestStreamPushRequestLine235--- PASS: TestScriptTokenBadJSON (0.01s)236=== CONT TestRegisterUploadedObjectReusesConnections2372026/10/01 12:50:54 ERROR Upload failed error=boom count=1238--- PASS: TestStreamPushRequestLine (0.02s)239=== CONT TestStreamPushBatchesUnderLoad240--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)241=== CONT TestSetClientTLSDoesNotMutateDefaultTransport242--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)243=== CONT TestStreamPushGivesUpOnDeadServer2442026/10/01 12:50:54 ERROR Upload failed error="connection refused" count=202452026/10/01 12:50:54 ERROR Server seems unavailable, giving up on batch untried=17246--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)247=== CONT TestSetClientTLS248--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)249=== CONT TestStreamPushIsolatesFailures2502026/10/01 12:50:54 ERROR Upload failed error="bad path" count=3251--- PASS: TestStreamPushIsolatesFailures (0.00s)252=== CONT TestClientSignaturesByStorePath253--- PASS: TestClientSignaturesByStorePath (0.00s)254=== CONT TestStreamPushReportsSignatures2552026/10/01 12:50:54 ERROR Upload failed error=boom count=1256--- PASS: TestStreamPushReportsSignatures (0.00s)257=== CONT TestStreamPushReportsEveryPath258--- PASS: TestStreamPushReportsEveryPath (0.00s)259=== CONT TestShellSplitErrors260--- PASS: TestShellSplitErrors (0.00s)261=== CONT TestPathInfoCACompatibility/null_ca_field262=== CONT TestPathInfoCACompatibility/new_structured_format_-_text263=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== CONT TestPathInfoCACompatibility/old_string_format_-_text266--- PASS: TestPathInfoCACompatibility (0.00s)267 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)268 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)269 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)270 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)271 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)272=== CONT TestRateLimiterFeedback/429_enables_limiter273=== RUN TestSetClientTLS/rejects_connection_without_client_cert274=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert275=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA276=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA277=== RUN TestSetClientTLS/preserves_debug_logging_transport278=== PAUSE TestSetClientTLS/preserves_debug_logging_transport279=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2802026/10/01 12:50:54 WARN Rate limiter enabled after throttle name=server-test rate=52812026/10/01 12:50:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:49183282=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2832026/10/01 12:50:54 WARN Rate limiter backed off name=server-test rate=5284=== CONT TestRateLimiterFeedback/503_enables_limiter2852026/10/01 12:50:54 WARN Rate limiter enabled after throttle name=server-test rate=5286=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2872026/10/01 12:50:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:49189288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2892026/10/01 12:50:54 WARN Rate limiter backed off name=server-test rate=5290--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)291 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)292 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)293=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)294--- PASS: TestRateLimiterFeedback (0.00s)295 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)298 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)299=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI300=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512301=== CONT TestParsePathInfoJSON/Nix_format302=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon303=== CONT TestParsePathInfoJSON/invalid_JSON304=== CONT TestParsePathInfoJSON/empty_input305--- PASS: TestPathInfoHashCompatibility (0.00s)306 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)308 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)309 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)310=== CONT TestParsePathInfoJSON/whitespace_only311=== CONT TestConvertHashToNix32/SRI_format_to_Nix32312=== CONT TestParsePathInfoJSON/Lix_format313=== CONT TestConvertHashToNix32/invalid_format314--- PASS: TestParsePathInfoJSON (0.00s)315 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)316 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)319 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)320=== CONT TestEncodeNixBase32/test_string_hash321=== CONT TestConvertHashToNix32/already_Nix32_format322=== CONT TestGetStorePathHash/valid_store_path323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)325 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)326 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)327=== CONT TestEncodeNixBase32/empty_input328=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error329--- PASS: TestEncodeNixBase32 (0.00s)330 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)331 --- PASS: TestEncodeNixBase32/empty_input (0.00s)332=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error333=== CONT TestGetStorePathHash/basename_without_hyphen_should_error334=== CONT TestSetClientTLSErrors/missing_cert_file335--- PASS: TestGetStorePathHash (0.00s)336 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)337 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)338 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)339 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)340=== CONT TestUploadMultipart_SupersededByPeer/exists341=== CONT TestSetClientTLSErrors/missing_key_file342=== CONT TestSetClientTLSErrors/invalid_ca_file343=== CONT TestSetClientTLSErrors/missing_ca_file344=== CONT TestUploadMultipart_SupersededByPeer/missing345=== CONT TestFilterOversizedClosures/no_limit_keeps_everything346=== CONT TestFilterOversizedClosures/all_closures_skipped3472026/10/01 12:50:54 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=50348=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3492026/10/01 12:50:54 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=2000350--- PASS: TestFilterOversizedClosures (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354=== CONT TestPartSizeForNAR/zero_stays_at_minimum355=== CONT TestPartSizeForNAR/1_TiB356=== CONT TestPartSizeForNAR/capped_at_5_GiB357=== CONT TestPartSizeForNAR/5_TiB_S3_max_object358=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum359=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts360=== CONT TestPartSizeForNAR/small_stays_at_minimum361--- PASS: TestPartSizeForNAR (0.00s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)364 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)369=== CONT TestSetClientTLS/rejects_connection_without_client_cert370--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)371 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)372 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)373=== CONT TestSetClientTLS/preserves_debug_logging_transport374--- PASS: TestDumpPathWriterError (0.04s)375=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA376--- PASS: TestSetClientTLSErrors (0.01s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)381--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)3822026/10/01 12:50:54 http: TLS handshake error from 127.0.0.1:49195: remote error: tls: bad certificate383--- PASS: TestDumpPathSingleFile (0.05s)384--- PASS: TestSetClientTLS (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)387 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld12".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-75714-2028051062/postgres1000970889/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-75714-2028051062/postgres1000970889/data -l logfile start421422/nix/var/nix/builds/nix-75714-2028051062/postgres1000970889:5432 - no response4232026-10-01 12:50:55.949 UTC [76617] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 12:50:55.949 UTC [76617] LOG: listening on Unix socket "/nix/var/nix/builds/nix-75714-2028051062/postgres1000970889/.s.PGSQL.5432"4252026-10-01 12:50:55.951 UTC [76624] LOG: database system was shut down at 2026-10-01 12:50:55 UTC4262026-10-01 12:50:55.952 UTC [76617] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-75714-2028051062/postgres1000970889:5432 - accepting connections428{"timestamp":"2026-10-01T12:50:56.163559Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6b334709-5faa-4492-bf0e-1dd0f7a9b590","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(10)"}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 12:50:56 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 12:50:57 INFO lead: released remote=192.0.2.1:12344762026/10/01 12:50:57 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 12:50:57 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (0.92s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestGCAdvisoryLockBlocksConcurrentRun482=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun483=== RUN TestGCBugBareHashReferences484=== PAUSE TestGCBugBareHashReferences485=== RUN TestGCMetrics486=== PAUSE TestGCMetrics487=== RUN TestPushDedupSurvivesConcurrentGC488=== PAUSE TestPushDedupSurvivesConcurrentGC489=== RUN TestDeduplicatedObjectsRecordedAsPending490=== PAUSE TestDeduplicatedObjectsRecordedAsPending491=== RUN TestGCSweepSkipsPendingObjects492=== PAUSE TestGCSweepSkipsPendingObjects493=== RUN TestTombstonedObjectOfferedWithoutWaiting494=== PAUSE TestTombstonedObjectOfferedWithoutWaiting495=== RUN TestGCSweepDeliversEachKeyOnce496=== PAUSE TestGCSweepDeliversEachKeyOnce497=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection498=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection499=== RUN TestForceGCDuringPushOffersSweptObject500=== PAUSE TestForceGCDuringPushOffersSweptObject501=== RUN TestFailedS3DeleteKeepsTombstone502=== PAUSE TestFailedS3DeleteKeepsTombstone503=== RUN TestSweepSkipsRowsLockedByPush504=== PAUSE TestSweepSkipsRowsLockedByPush505=== RUN TestRegisterCompletedObjectNeedsPendingRow506=== PAUSE TestRegisterCompletedObjectNeedsPendingRow507=== RUN TestGetExistingObjectsLocksRows508=== PAUSE TestGetExistingObjectsLocksRows509=== RUN TestSweepRechecksPendingAfterLocking510=== PAUSE TestSweepRechecksPendingAfterLocking511=== RUN TestPushWaitsForSweepHoldingRow512=== PAUSE TestPushWaitsForSweepHoldingRow513=== RUN TestCommitRacingPendingCleanupKeepsObjects514=== PAUSE TestCommitRacingPendingCleanupKeepsObjects515=== RUN TestGCEndsOnShutdown516=== PAUSE TestGCEndsOnShutdown517=== RUN TestGCTaskStore_StartNew518=== PAUSE TestGCTaskStore_StartNew519=== RUN TestGCTaskStore_DeduplicateSameParams520=== PAUSE TestGCTaskStore_DeduplicateSameParams521=== RUN TestGCTaskStore_ConflictDifferentParams522=== PAUSE TestGCTaskStore_ConflictDifferentParams523=== RUN TestGCTaskStore_GetEmpty524=== PAUSE TestGCTaskStore_GetEmpty525=== RUN TestGCTaskStore_GetReturnsLatest526=== PAUSE TestGCTaskStore_GetReturnsLatest527=== RUN TestGCTaskStore_CompletedAllowsNewTask528=== PAUSE TestGCTaskStore_CompletedAllowsNewTask529=== RUN TestGCTaskStore_PhaseUpdates530=== PAUSE TestGCTaskStore_PhaseUpdates531=== RUN TestGCTaskStore_Fail532=== PAUSE TestGCTaskStore_Fail533=== RUN TestGracefulShutdownDrainsInflight534=== PAUSE TestGracefulShutdownDrainsInflight535=== RUN TestService_healthCheckHandler536=== PAUSE TestService_healthCheckHandler537=== RUN TestService_readinessHandler538=== PAUSE TestService_readinessHandler539=== RUN TestGenerateLandingPage540=== PAUSE TestGenerateLandingPage541=== RUN TestCacheConfigHandlerMaxNarSize542=== PAUSE TestCacheConfigHandlerMaxNarSize543=== RUN TestCreatePendingClosureRejectsOversizedNAR544=== PAUSE TestCreatePendingClosureRejectsOversizedNAR545=== RUN TestNARDeduplicationMetadataUploadBug546=== PAUSE TestNARDeduplicationMetadataUploadBug547=== RUN TestMetricsInventory548=== PAUSE TestMetricsInventory549=== RUN TestService_NativeMTLS550=== PAUSE TestService_NativeMTLS551=== RUN TestServerTLSConfig552=== PAUSE TestServerTLSConfig553=== RUN TestMultipartCleanup554=== PAUSE TestMultipartCleanup555=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded556=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded557=== RUN TestPendingCleanupUsesOneCutoff558=== PAUSE TestPendingCleanupUsesOneCutoff559=== RUN TestObjectStatsTrigger560=== PAUSE TestObjectStatsTrigger561=== RUN TestOrphanedObjectsGC562=== PAUSE TestOrphanedObjectsGC563=== RUN TestOrphanedObjectsGCStressTest564=== PAUSE TestOrphanedObjectsGCStressTest565=== RUN TestCreatePin_ReservedPins566=== PAUSE TestCreatePin_ReservedPins567=== RUN TestPresentReportsOnlyClosureRoots568=== PAUSE TestPresentReportsOnlyClosureRoots569=== RUN TestPresentNotReportedWhileGCDeletesClosure570=== PAUSE TestPresentNotReportedWhileGCDeletesClosure571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyOutlastsServerWriteTimeout590=== PAUSE TestReadProxyOutlastsServerWriteTimeout591=== RUN TestReadProxyConditionalGet592=== PAUSE TestReadProxyConditionalGet593=== RUN TestReadProxyRootRedirectsToIndexHTML594=== PAUSE TestReadProxyRootRedirectsToIndexHTML595=== RUN TestReadProxyDisabled596=== PAUSE TestReadProxyDisabled597=== RUN TestReadRedirectNar598=== PAUSE TestReadRedirectNar599=== RUN TestReadRedirectKeepsNarinfoProxied600=== PAUSE TestReadRedirectKeepsNarinfoProxied601=== RUN TestReadProxyRangeRequest602=== PAUSE TestReadProxyRangeRequest603=== RUN TestReadRedirectUsesPublicS3URL604=== PAUSE TestReadRedirectUsesPublicS3URL605=== RUN TestPush_OverlappingRootsStoreOneRowPerKey606=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey607=== RUN TestPush_CompleteCommitsEveryRoot608=== PAUSE TestPush_CompleteCommitsEveryRoot609=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit610=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit611=== RUN TestPush_RejectsBadRequests612=== PAUSE TestPush_RejectsBadRequests613=== RUN TestPush_SignsNarinfosOfItsPendingObjects614=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects615=== RUN TestRedundantMultipartUpload616=== PAUSE TestRedundantMultipartUpload617=== RUN TestCompleteMultipartUpload_ErrorButObjectExists618=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists619=== RUN TestCompletedNarNotReofferedAcrossClosures620=== PAUSE TestCompletedNarNotReofferedAcrossClosures621=== RUN TestPresignedUploadRegisteredBeforeCommit622=== PAUSE TestPresignedUploadRegisteredBeforeCommit623=== RUN TestService_Rustfstest624=== PAUSE TestService_Rustfstest625=== RUN TestParseSize626=== PAUSE TestParseSize627=== RUN TestSkippedUploadsHandler628=== PAUSE TestSkippedUploadsHandler629=== RUN TestSystemdListenerNotActivated630--- PASS: TestSystemdListenerNotActivated (0.00s)631=== RUN TestWatchdogBeatsWhenHealthy632--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)633=== RUN TestWatchdogSkipsWhenUnhealthy6342026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 12:50:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"644--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)645=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle646=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle647=== RUN TestProxyWriteTimeout648=== PAUSE TestProxyWriteTimeout649=== RUN TestPendingClosureWriteTimeout650=== PAUSE TestPendingClosureWriteTimeout651=== RUN TestIsValidUploadKey652=== PAUSE TestIsValidUploadKey653=== RUN TestUploadHandlersRejectInvalidKeys654=== PAUSE TestUploadHandlersRejectInvalidKeys655=== RUN TestUploadHandlersRejectOversizedBody656=== PAUSE TestUploadHandlersRejectOversizedBody657=== RUN TestService_cleanupPendingClosuresHandler658=== PAUSE TestService_cleanupPendingClosuresHandler659=== RUN TestService_createPendingClosureHandler660=== PAUSE TestService_createPendingClosureHandler661=== RUN TestService_verifyS3Integrity662=== PAUSE TestService_verifyS3Integrity663=== RUN TestCompleteMultipartUnregistered664=== PAUSE TestCompleteMultipartUnregistered665=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT666=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT667=== CONT TestService_AuthMiddleware668=== CONT TestCreatePendingClosureRejectsOversizedNAR669=== CONT TestDeduplicatedObjectsRecordedAsPending670=== CONT TestGCEndsOnShutdown671=== CONT TestGCTaskStore_StartNew672--- PASS: TestGCTaskStore_StartNew (0.00s)673=== CONT TestCommitRacingPendingCleanupKeepsObjects674=== CONT TestCacheConfigHandlerMaxNarSize6752026/10/01 12:50:57 INFO Received uploads request method=POST path=/api/pending_closures676=== CONT TestPushWaitsForSweepHoldingRow677=== CONT TestSweepRechecksPendingAfterLocking678--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)679--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)680=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT681=== CONT TestGenerateLandingPage682=== CONT TestGetExistingObjectsLocksRows683=== CONT TestRegisterCompletedObjectNeedsPendingRow684--- PASS: TestGenerateLandingPage (0.00s)685=== CONT TestSweepSkipsRowsLockedByPush6862026/10/01 12:50:57 INFO Received uploads request method=POST path=/api/pending_closures687--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.53s)688=== CONT TestFailedS3DeleteKeepsTombstone6892026/10/01 12:50:58 INFO Aborted multipart uploads count=0 kept=06902026/10/01 12:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period6912026/10/01 12:50:58 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=06922026/10/01 12:50:58 INFO Vacuumed table table=pending_closures6932026/10/01 12:50:58 INFO Vacuumed table table=pending_objects6942026/10/01 12:50:58 INFO Vacuumed table table=multipart_uploads6952026/10/01 12:50:58 INFO Vacuumed table table=closures6962026/10/01 12:50:58 INFO Vacuumed table table=objects697--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.82s)698=== CONT TestForceGCDuringPushOffersSweptObject699=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows700=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows701=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check702=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check703=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection7042026/10/01 12:50:58 INFO Aborted multipart uploads count=0 kept=07052026/10/01 12:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period7062026/10/01 12:50:58 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 12:50:58 INFO Vacuumed table table=pending_closures7082026/10/01 12:50:58 INFO Vacuumed table table=pending_objects7092026/10/01 12:50:58 INFO Vacuumed table table=multipart_uploads7102026/10/01 12:50:58 INFO Vacuumed table table=closures7112026/10/01 12:50:58 INFO Vacuumed table table=objects7122026/10/01 12:50:58 INFO Aborted multipart uploads count=0 kept=07132026/10/01 12:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period7142026/10/01 12:50:58 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 12:50:58 INFO Vacuumed table table=pending_closures7162026/10/01 12:50:58 INFO Vacuumed table table=pending_objects7172026/10/01 12:50:58 INFO Vacuumed table table=multipart_uploads7182026/10/01 12:50:58 INFO Vacuumed table table=closures7192026/10/01 12:50:58 INFO Vacuumed table table=objects720--- PASS: TestSweepSkipsRowsLockedByPush (0.95s)721=== CONT TestGCSweepDeliversEachKeyOnce7222026/10/01 12:50:58 INFO Received uploads request method=POST path=/api/pending_closures723--- PASS: TestGCEndsOnShutdown (1.27s)724=== CONT TestTombstonedObjectOfferedWithoutWaiting7252026/10/01 12:50:58 INFO Aborted multipart uploads count=0 kept=07262026/10/01 12:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period7272026/10/01 12:50:58 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=07282026/10/01 12:50:58 INFO Vacuumed table table=pending_closures7292026/10/01 12:50:58 INFO Vacuumed table table=pending_objects7302026/10/01 12:50:58 INFO Vacuumed table table=multipart_uploads7312026/10/01 12:50:58 INFO Vacuumed table table=closures7322026/10/01 12:50:58 INFO Vacuumed table table=objects733--- PASS: TestSweepRechecksPendingAfterLocking (1.52s)734=== CONT TestGCSweepSkipsPendingObjects735--- PASS: TestPushWaitsForSweepHoldingRow (1.58s)736=== CONT TestClientSharedPathCommittedMidPush7372026/10/01 12:50:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"738--- PASS: TestService_AuthMiddleware (1.62s)739=== CONT TestPushDedupSurvivesConcurrentGC740--- PASS: TestGetExistingObjectsLocksRows (1.82s)741=== CONT TestGCMetrics742--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.96s)743=== CONT TestGCBugBareHashReferences7442026/10/01 12:50:59 INFO Received uploads request method=POST path=/api/pending_closures745--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.25s)746=== CONT TestGCAdvisoryLockBlocksConcurrentRun7472026/10/01 12:50:59 INFO Received uploads request method=POST path=/api/pending_closures7482026/10/01 12:50:59 INFO Aborted multipart uploads count=0 kept=07492026/10/01 12:50:59 WARN Force mode enabled - objects will be deleted immediately without grace period7502026/10/01 12:50:59 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."7512026/10/01 12:50:59 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."752--- PASS: TestFailedS3DeleteKeepsTombstone (1.99s)753=== CONT TestLeadEndsOnShutdown7542026/10/01 12:51:00 INFO Received uploads request method=POST path=/api/pending_closures755--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.02s)756=== CONT TestLeadElectsOneAndHandsOver7572026/10/01 12:51:00 INFO Aborted multipart uploads count=0 kept=07582026/10/01 12:51:00 WARN Force mode enabled - objects will be deleted immediately without grace period7592026/10/01 12:51:00 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=07602026/10/01 12:51:00 INFO Vacuumed table table=pending_closures7612026/10/01 12:51:00 INFO Vacuumed table table=pending_objects7622026/10/01 12:51:00 INFO Vacuumed table table=multipart_uploads7632026/10/01 12:51:00 INFO Vacuumed table table=closures7642026/10/01 12:51:00 INFO Vacuumed table table=objects765--- PASS: TestGCSweepDeliversEachKeyOnce (2.00s)766=== CONT TestConnectWaitsForAPeerMigration7672026/10/01 12:51:00 INFO Received uploads request method=POST path=/api/pending_closures768--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.78s)769=== CONT TestResolveDBConnectionString770=== RUN TestResolveDBConnectionString/flag_wins771=== PAUSE TestResolveDBConnectionString/flag_wins772=== RUN TestResolveDBConnectionString/file_when_flag_empty773=== PAUSE TestResolveDBConnectionString/file_when_flag_empty774=== RUN TestResolveDBConnectionString/missing_file_is_an_error775=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error776=== RUN TestResolveDBConnectionString/PGHOST_allows_empty777=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty778=== RUN TestResolveDBConnectionString/nothing_configured779=== PAUSE TestResolveDBConnectionString/nothing_configured780=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7812026/10/01 12:51:00 INFO Received uploads request method=POST path=/api/pending_closures7822026/10/01 12:51:00 INFO Aborted multipart uploads count=0 kept=07832026/10/01 12:51:00 WARN Force mode enabled - objects will be deleted immediately without grace period7842026/10/01 12:51:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07852026/10/01 12:51:00 INFO Vacuumed table table=pending_closures7862026/10/01 12:51:00 INFO Vacuumed table table=pending_objects7872026/10/01 12:51:00 INFO Vacuumed table table=multipart_uploads7882026/10/01 12:51:00 INFO Vacuumed table table=closures7892026/10/01 12:51:00 INFO Vacuumed table table=objects790--- PASS: TestGCSweepSkipsPendingObjects (1.86s)791=== CONT TestClientFallsBackToClosures7922026/10/01 12:51:01 INFO Received uploads request method=POST path=/api/pending_closures7932026/10/01 12:51:01 INFO Received push request method=POST path=/api/pushes7942026/10/01 12:51:01 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)7952026/10/01 12:51:01 INFO Uploading f59a1w5n1lgq8mjyk5xfxjcy0yjzhsqj-top (256B)7962026/10/01 12:51:01 INFO Uploading dhcyfzcnmn1hjwkx9y4w58cz6zbzp2qd-shared-dep (136B)7972026/10/01 12:51:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7982026/10/01 12:51:01 WARN Failed to register uploaded object key=nar/1vc3ac0l4jwxcdqpas9if9zgyv1n3lhrhb9s0yhvp59xji620clr.nar.zst error="server returned 404: 404 page not found\n"7992026/10/01 12:51:01 WARN Failed to register uploaded object key=f59a1w5n1lgq8mjyk5xfxjcy0yjzhsqj.ls error="server returned 404: 404 page not found\n"8002026/10/01 12:51:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8012026/10/01 12:51:01 WARN Failed to register uploaded object key=dhcyfzcnmn1hjwkx9y4w58cz6zbzp2qd.ls error="server returned 404: 404 page not found\n"8022026/10/01 12:51:01 INFO Signed narinfos id=1 count=28032026/10/01 12:51:01 INFO Uploading 2 narinfos8042026/10/01 12:51:01 INFO Aborted multipart uploads count=0 kept=08052026/10/01 12:51:01 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=08062026/10/01 12:51:01 INFO Vacuumed table table=pending_closures8072026/10/01 12:51:01 INFO Vacuumed table table=pending_objects8082026/10/01 12:51:01 WARN Failed to register uploaded object key=f59a1w5n1lgq8mjyk5xfxjcy0yjzhsqj.narinfo error="server returned 404: 404 page not found\n"8092026/10/01 12:51:01 INFO Vacuumed table table=multipart_uploads8102026/10/01 12:51:01 INFO Received complete push request method=POST path=/api/pushes/1/complete8112026/10/01 12:51:01 WARN Failed to register uploaded object key=dhcyfzcnmn1hjwkx9y4w58cz6zbzp2qd.narinfo error="server returned 404: 404 page not found\n"8122026/10/01 12:51:01 INFO Vacuumed table table=closures8132026/10/01 12:51:01 INFO Upload complete. (168ms)8142026/10/01 12:51:01 INFO Vacuumed table table=objects815=== NAME TestClientSharedPathCommittedMidPush816 client_integration_test.go:680: Retrieved narinfo from S3:817 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientSharedPathCommittedMidPush2202162286/001/store/dhcyfzcnmn1hjwkx9y4w58cz6zbzp2qd-shared-dep818 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst819 Compression: zstd820 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82821 NarSize: 136822 References: 823 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n824 client_integration_test.go:680: Retrieved narinfo from S3:825 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientSharedPathCommittedMidPush2202162286/001/store/f59a1w5n1lgq8mjyk5xfxjcy0yjzhsqj-top826 URL: nar/1vc3ac0l4jwxcdqpas9if9zgyv1n3lhrhb9s0yhvp59xji620clr.nar.zst827 Compression: zstd828 NarHash: sha256:1vc3ac0l4jwxcdqpas9if9zgyv1n3lhrhb9s0yhvp59xji620clr829 NarSize: 256830 References: /nix/var/nix/builds/nix-75714-2028051062/TestClientSharedPathCommittedMidPush2202162286/001/store/dhcyfzcnmn1hjwkx9y4w58cz6zbzp2qd-shared-dep831 CA: text:sha256:1wzfcvx7sq59gd0k5pxpm0hs3v3mfsmbz9cj6m63cb36cglmix5q832--- PASS: TestClientSharedPathCommittedMidPush (2.44s)833=== CONT TestClientPushesUseOnePush8342026/10/01 12:51:01 INFO Aborted multipart uploads count=0 kept=08352026/10/01 12:51:01 WARN Force mode enabled - objects will be deleted immediately without grace period8362026/10/01 12:51:01 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=08372026/10/01 12:51:01 INFO Vacuumed table table=pending_closures8382026/10/01 12:51:01 INFO Vacuumed table table=pending_objects8392026/10/01 12:51:01 INFO Vacuumed table table=multipart_uploads8402026/10/01 12:51:01 INFO Vacuumed table table=closures8412026/10/01 12:51:01 INFO Vacuumed table table=objects842--- PASS: TestPushDedupSurvivesConcurrentGC (2.42s)843=== CONT TestPinProtectsFromGC8442026/10/01 12:51:01 INFO Aborted multipart uploads count=0 kept=08452026/10/01 12:51:01 WARN Force mode enabled - objects will be deleted immediately without grace period8462026/10/01 12:51:01 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=08472026/10/01 12:51:01 INFO Vacuumed table table=pending_closures8482026/10/01 12:51:01 INFO Vacuumed table table=pending_objects8492026/10/01 12:51:01 INFO Vacuumed table table=multipart_uploads8502026/10/01 12:51:01 INFO Vacuumed table table=closures8512026/10/01 12:51:01 INFO Vacuumed table table=objects852--- PASS: TestGCMetrics (2.29s)853=== CONT TestReadRedirectNar854--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.21s)855=== CONT TestCompleteMultipartUnregistered856--- PASS: TestGCBugBareHashReferences (2.56s)857=== CONT TestService_verifyS3Integrity8582026/10/01 12:51:02 INFO lead: acquired remote=192.0.2.1:12348592026/10/01 12:51:02 INFO lead: released remote=192.0.2.1:1234860--- PASS: TestLeadEndsOnShutdown (2.28s)861=== CONT TestService_createPendingClosureHandler8622026/10/01 12:51:02 INFO lead: acquired remote=192.0.2.1:12348632026/10/01 12:51:02 INFO lead: released remote=192.0.2.1:12348642026/10/01 12:51:02 INFO lead: acquired remote=192.0.2.1:12348652026/10/01 12:51:02 INFO lead: released remote=192.0.2.1:1234866--- PASS: TestLeadElectsOneAndHandsOver (2.51s)867=== CONT TestService_cleanupPendingClosuresHandler868--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.76s)869=== CONT TestUploadHandlersRejectOversizedBody870=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure871=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure872=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart873=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart874=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts875=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts876=== CONT TestUploadHandlersRejectInvalidKeys877=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info878=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info879=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal880=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal881=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key882=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key883=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key884=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key885=== CONT TestIsValidUploadKey886=== RUN TestIsValidUploadKey/narinfo887=== PAUSE TestIsValidUploadKey/narinfo888=== RUN TestIsValidUploadKey/nar_zst889=== PAUSE TestIsValidUploadKey/nar_zst890=== RUN TestIsValidUploadKey/nar_xz891=== PAUSE TestIsValidUploadKey/nar_xz892=== RUN TestIsValidUploadKey/nar_plain893=== PAUSE TestIsValidUploadKey/nar_plain894=== RUN TestIsValidUploadKey/listing895=== PAUSE TestIsValidUploadKey/listing896=== RUN TestIsValidUploadKey/build_log897=== PAUSE TestIsValidUploadKey/build_log898=== RUN TestIsValidUploadKey/build_log_home-manager_file899=== PAUSE TestIsValidUploadKey/build_log_home-manager_file900=== RUN TestIsValidUploadKey/build_log_plus_in_name901=== PAUSE TestIsValidUploadKey/build_log_plus_in_name902=== RUN TestIsValidUploadKey/build_log_question_mark903=== PAUSE TestIsValidUploadKey/build_log_question_mark904=== RUN TestIsValidUploadKey/build_log_equals905=== PAUSE TestIsValidUploadKey/build_log_equals906=== RUN TestIsValidUploadKey/realisation907=== PAUSE TestIsValidUploadKey/realisation908=== RUN TestIsValidUploadKey/realisation_plus_in_output909=== PAUSE TestIsValidUploadKey/realisation_plus_in_output910=== RUN TestIsValidUploadKey/nix-cache-info911=== PAUSE TestIsValidUploadKey/nix-cache-info912=== RUN TestIsValidUploadKey/index.html913=== PAUSE TestIsValidUploadKey/index.html914=== RUN TestIsValidUploadKey/narinfo_key,_nar_type915=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type916=== RUN TestIsValidUploadKey/nar_key,_narinfo_type917=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type918=== RUN TestIsValidUploadKey/listing_key,_narinfo_type919=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type920=== RUN TestIsValidUploadKey/traversal921=== PAUSE TestIsValidUploadKey/traversal922=== RUN TestIsValidUploadKey/traversal_nar923=== PAUSE TestIsValidUploadKey/traversal_nar924=== RUN TestIsValidUploadKey/absolute925=== PAUSE TestIsValidUploadKey/absolute926=== RUN TestIsValidUploadKey/empty_key927=== PAUSE TestIsValidUploadKey/empty_key928=== RUN TestIsValidUploadKey/unknown_type929=== PAUSE TestIsValidUploadKey/unknown_type930=== CONT TestPendingClosureWriteTimeout931=== RUN TestPendingClosureWriteTimeout/empty932=== PAUSE TestPendingClosureWriteTimeout/empty933=== RUN TestPendingClosureWriteTimeout/400_objects934=== PAUSE TestPendingClosureWriteTimeout/400_objects935=== RUN TestPendingClosureWriteTimeout/670k_objects936=== PAUSE TestPendingClosureWriteTimeout/670k_objects937=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline938=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline939=== CONT TestProxyWriteTimeout940=== RUN TestProxyWriteTimeout/narinfo941=== PAUSE TestProxyWriteTimeout/narinfo942=== RUN TestProxyWriteTimeout/1_GiB_nar943=== PAUSE TestProxyWriteTimeout/1_GiB_nar944=== RUN TestProxyWriteTimeout/10_GiB_nar945=== PAUSE TestProxyWriteTimeout/10_GiB_nar946=== RUN TestProxyWriteTimeout/unknown_size947=== PAUSE TestProxyWriteTimeout/unknown_size948=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9492026/10/01 12:51:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9502026/10/01 12:51:03 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst951--- PASS: TestCompleteMultipartUnregistered (1.47s)952=== CONT TestSkippedUploadsHandler9532026/10/01 12:51:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000954--- PASS: TestSkippedUploadsHandler (0.00s)955=== CONT TestParseSize956--- PASS: TestParseSize (0.00s)957=== CONT TestService_Rustfstest9582026/10/01 12:51:03 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/01 12:51:03 INFO Received uploads request method=POST path=/api/pending_closures9602026/10/01 12:51:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9612026/10/01 12:51:03 INFO Uploading v94blqc75nrkrvgahqbxqjpq0gwqq1vs-b (248B)9622026/10/01 12:51:03 INFO Uploading 36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx-shared-dep (136B)9632026/10/01 12:51:03 WARN Failed to register uploaded object key=36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx.ls error="server returned 404: 404 page not found\n"9642026/10/01 12:51:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9652026/10/01 12:51:03 WARN Failed to register uploaded object key=v94blqc75nrkrvgahqbxqjpq0gwqq1vs.ls error="server returned 404: 404 page not found\n"9662026/10/01 12:51:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9672026/10/01 12:51:03 WARN Failed to register uploaded object key=dvcz17kh1rq0a1sszshz66iqrw4hnk3j.ls error="server returned 404: 404 page not found\n"9682026/10/01 12:51:03 WARN Failed to register uploaded object key=nar/1idszblwkqhvnrrpv3a6pm15kp26s0fbs286zcg4gi7d30ypn8qw.nar.zst error="server returned 404: 404 page not found\n"9692026/10/01 12:51:03 INFO Signed narinfos id=1 count=29702026/10/01 12:51:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9712026/10/01 12:51:03 INFO Signed narinfos id=2 count=29722026/10/01 12:51:03 INFO Uploading 4 narinfos9732026/10/01 12:51:03 WARN Failed to register uploaded object key=36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx.narinfo error="server returned 404: 404 page not found\n"9742026/10/01 12:51:03 WARN Failed to register uploaded object key=dvcz17kh1rq0a1sszshz66iqrw4hnk3j.narinfo error="server returned 404: 404 page not found\n"9752026/10/01 12:51:03 WARN Failed to register uploaded object key=v94blqc75nrkrvgahqbxqjpq0gwqq1vs.narinfo error="server returned 404: 404 page not found\n"9762026/10/01 12:51:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9772026/10/01 12:51:03 WARN Failed to register uploaded object key=36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx.narinfo error="server returned 404: 404 page not found\n"9782026/10/01 12:51:03 INFO Completed upload id=19792026/10/01 12:51:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9802026/10/01 12:51:03 INFO Completed upload id=29812026/10/01 12:51:03 INFO Upload complete. (178ms)982=== NAME TestClientFallsBackToClosures983 client_pushes_test.go:112: Retrieved narinfo from S3:984 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientFallsBackToClosures663811482/001/store/36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx-shared-dep985 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst986 Compression: zstd987 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82988 NarSize: 136989 References: 990 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n991 client_pushes_test.go:112: Retrieved narinfo from S3:992 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientFallsBackToClosures663811482/001/store/dvcz17kh1rq0a1sszshz66iqrw4hnk3j-a993 URL: nar/1idszblwkqhvnrrpv3a6pm15kp26s0fbs286zcg4gi7d30ypn8qw.nar.zst994 Compression: zstd995 NarHash: sha256:1idszblwkqhvnrrpv3a6pm15kp26s0fbs286zcg4gi7d30ypn8qw996 NarSize: 248997 References: /nix/var/nix/builds/nix-75714-2028051062/TestClientFallsBackToClosures663811482/001/store/36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx-shared-dep998 CA: text:sha256:1bzgz97b3ya9qn0pi8xlv7cck159imj62f2zysfcw06nfkg7rhr2999 client_pushes_test.go:112: Retrieved narinfo from S3:1000 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientFallsBackToClosures663811482/001/store/v94blqc75nrkrvgahqbxqjpq0gwqq1vs-b1001 URL: nar/1idszblwkqhvnrrpv3a6pm15kp26s0fbs286zcg4gi7d30ypn8qw.nar.zst1002 Compression: zstd1003 NarHash: sha256:1idszblwkqhvnrrpv3a6pm15kp26s0fbs286zcg4gi7d30ypn8qw1004 NarSize: 2481005 References: /nix/var/nix/builds/nix-75714-2028051062/TestClientFallsBackToClosures663811482/001/store/36zkc6yxzfq38fhhi1ylz7hp6ygw0fsx-shared-dep1006 CA: text:sha256:1bzgz97b3ya9qn0pi8xlv7cck159imj62f2zysfcw06nfkg7rhr21007--- PASS: TestClientFallsBackToClosures (2.74s)1008=== CONT TestPresignedUploadRegisteredBeforeCommit1009--- PASS: TestReadRedirectNar (2.13s)1010=== CONT TestCompletedNarNotReofferedAcrossClosures10112026/10/01 12:51:03 INFO Received push request method=POST path=/api/pushes10122026/10/01 12:51:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10132026/10/01 12:51:03 INFO Uploading ffibqx6d7r3ildh8g0miyakaag5dvq2f-a (248B)10142026/10/01 12:51:03 INFO Uploading fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9-shared-dep (136B)10152026/10/01 12:51:03 WARN Failed to register uploaded object key=ffibqx6d7r3ildh8g0miyakaag5dvq2f.ls error="server returned 404: 404 page not found\n"10162026/10/01 12:51:03 WARN Failed to register uploaded object key=nar/0dc8d22cf1s3n3hqppqhzgvg208cv2bg9wqmn8kz2p73vm3yd5mw.nar.zst error="server returned 404: 404 page not found\n"10172026/10/01 12:51:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10182026/10/01 12:51:03 WARN Failed to register uploaded object key=b1dhd5lyygcbgcrsqahi6n23ahprjw51.ls error="server returned 404: 404 page not found\n"10192026/10/01 12:51:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/10/01 12:51:03 WARN Failed to register uploaded object key=fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9.ls error="server returned 404: 404 page not found\n"10212026/10/01 12:51:03 INFO Signed narinfos id=1 count=310222026/10/01 12:51:03 INFO Uploading 3 narinfos10232026/10/01 12:51:03 WARN Failed to register uploaded object key=fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9.narinfo error="server returned 404: 404 page not found\n"10242026/10/01 12:51:03 INFO Received complete push request method=POST path=/api/pushes/1/complete10252026/10/01 12:51:03 WARN Failed to register uploaded object key=ffibqx6d7r3ildh8g0miyakaag5dvq2f.narinfo error="server returned 404: 404 page not found\n"10262026/10/01 12:51:03 WARN Failed to register uploaded object key=b1dhd5lyygcbgcrsqahi6n23ahprjw51.narinfo error="server returned 404: 404 page not found\n"10272026/10/01 12:51:03 INFO Upload complete. (185ms)1028=== NAME TestClientPushesUseOnePush1029 client_pushes_test.go:97: Retrieved narinfo from S3:1030 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientPushesUseOnePush2650002275/001/store/fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9-shared-dep1031 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1032 Compression: zstd1033 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821034 NarSize: 1361035 References: 1036 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1037 client_pushes_test.go:97: Retrieved narinfo from S3:1038 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientPushesUseOnePush2650002275/001/store/ffibqx6d7r3ildh8g0miyakaag5dvq2f-a1039 URL: nar/0dc8d22cf1s3n3hqppqhzgvg208cv2bg9wqmn8kz2p73vm3yd5mw.nar.zst1040 Compression: zstd1041 NarHash: sha256:0dc8d22cf1s3n3hqppqhzgvg208cv2bg9wqmn8kz2p73vm3yd5mw1042 NarSize: 2481043 References: /nix/var/nix/builds/nix-75714-2028051062/TestClientPushesUseOnePush2650002275/001/store/fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9-shared-dep1044 CA: text:sha256:0q5pm02mxrd7rbch6j36jn94py886nyxh1ba8rmpwdhcjz434l791045 client_pushes_test.go:97: Retrieved narinfo from S3:1046 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientPushesUseOnePush2650002275/001/store/b1dhd5lyygcbgcrsqahi6n23ahprjw51-b1047 URL: nar/0dc8d22cf1s3n3hqppqhzgvg208cv2bg9wqmn8kz2p73vm3yd5mw.nar.zst1048 Compression: zstd1049 NarHash: sha256:0dc8d22cf1s3n3hqppqhzgvg208cv2bg9wqmn8kz2p73vm3yd5mw1050 NarSize: 2481051 References: /nix/var/nix/builds/nix-75714-2028051062/TestClientPushesUseOnePush2650002275/001/store/fz21w1r2hsx2ky2hq8f7nvyi0g5sc9x9-shared-dep1052 CA: text:sha256:0q5pm02mxrd7rbch6j36jn94py886nyxh1ba8rmpwdhcjz434l791053--- PASS: TestClientPushesUseOnePush (2.38s)1054=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10552026/10/01 12:51:04 INFO Received uploads request method=POST path=/api/pending_closures1056=== NAME TestPinProtectsFromGC1057 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-75714-2028051062/TestPinProtectsFromGC3022885204/001/store/zilrvbcdyvxng2jz7c9lfxs29di2vzkc-pinned-file.txt1058 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-75714-2028051062/TestPinProtectsFromGC3022885204/001/store/mislnvxk449p8jf2j7irsknfg2b4hav0-unpinned-file.txt10592026/10/01 12:51:04 INFO Received push request method=POST path=/api/pushes10602026/10/01 12:51:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10612026/10/01 12:51:04 INFO Uploading zilrvbcdyvxng2jz7c9lfxs29di2vzkc-pinned-file.txt (128B)10622026/10/01 12:51:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10632026/10/01 12:51:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10642026/10/01 12:51:04 WARN Failed to register uploaded object key=zilrvbcdyvxng2jz7c9lfxs29di2vzkc.ls error="server returned 404: 404 page not found\n"10652026/10/01 12:51:04 INFO Signed narinfos id=1 count=110662026/10/01 12:51:04 INFO Uploading 1 narinfos10672026/10/01 12:51:04 INFO Received complete push request method=POST path=/api/pushes/1/complete10682026/10/01 12:51:04 WARN Failed to register uploaded object key=zilrvbcdyvxng2jz7c9lfxs29di2vzkc.narinfo error="server returned 404: 404 page not found\n"10692026/10/01 12:51:04 INFO Upload complete. (193ms)10702026/10/01 12:51:04 INFO Received uploads request method=POST path=/api/pending_closures10712026/10/01 12:51:04 INFO Received uploads request method=POST path=/api/pending_closures10722026/10/01 12:51:04 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/01 12:51:04 INFO Received push request method=POST path=/api/pushes10742026/10/01 12:51:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10752026/10/01 12:51:04 INFO Uploading mislnvxk449p8jf2j7irsknfg2b4hav0-unpinned-file.txt (128B)10762026/10/01 12:51:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10772026/10/01 12:51:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10782026/10/01 12:51:04 WARN Failed to register uploaded object key=mislnvxk449p8jf2j7irsknfg2b4hav0.ls error="server returned 404: 404 page not found\n"10792026/10/01 12:51:04 INFO Signed narinfos id=2 count=110802026/10/01 12:51:04 INFO Uploading 1 narinfos10812026/10/01 12:51:04 INFO Received complete push request method=POST path=/api/pushes/2/complete10822026/10/01 12:51:04 WARN Failed to register uploaded object key=mislnvxk449p8jf2j7irsknfg2b4hav0.narinfo error="server returned 404: 404 page not found\n"10832026/10/01 12:51:04 INFO Upload complete. (162ms)10842026/10/01 12:51:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures10852026/10/01 12:51:04 INFO Garbage collection started10862026/10/01 12:51:04 INFO Aborted multipart uploads count=0 kept=010872026/10/01 12:51:04 WARN Force mode enabled - objects will be deleted immediately without grace period10882026/10/01 12:51:04 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=010892026/10/01 12:51:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10902026/10/01 12:51:04 INFO Aborted multipart uploads count=0 kept=010912026/10/01 12:51:04 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/01 12:51:04 INFO Vacuumed table table=pending_closures10932026/10/01 12:51:04 INFO Vacuumed table table=pending_objects10942026/10/01 12:51:04 INFO Vacuumed table table=multipart_uploads10952026/10/01 12:51:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10962026/10/01 12:51:04 INFO Vacuumed table table=closures10972026/10/01 12:51:04 INFO Aborted multipart uploads count=1 kept=010982026/10/01 12:51:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10992026-10-01 12:51:05.008 UTC [77356] ERROR: Closure does not exist: id=111002026-10-01 12:51:05.008 UTC [77356] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11012026-10-01 12:51:05.008 UTC [77356] STATEMENT: -- name: CommitPendingClosure :exec1102 SELECT commit_pending_closure($1::bigint)1103 1104--- PASS: TestService_cleanupPendingClosuresHandler (2.25s)1105=== CONT TestRedundantMultipartUpload11062026/10/01 12:51:05 INFO Vacuumed table table=objects11072026/10/01 12:51:05 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestService_Rustfstest (2.26s)1109=== CONT TestPush_SignsNarinfosOfItsPendingObjects11102026/10/01 12:51:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11112026/10/01 12:51:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11122026/10/01 12:51:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLmYwNTQwOTY0LTFhMzktNDNiMy04OGE3LTQ4ODJiNGYwNjVmMHgxNzkwODU5MDY0MjYyMTgzMDAw parts=1011132026/10/01 12:51:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11142026/10/01 12:51:05 INFO Completed upload id=111152026/10/01 12:51:05 INFO Received uploads request method=POST path=/api/pending_closures11162026/10/01 12:51:05 INFO Received uploads request method=POST path=/api/pending_closures11172026/10/01 12:51:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11182026/10/01 12:51:05 WARN Found objects in DB but missing from S3, will re-upload count=11119--- PASS: TestService_verifyS3Integrity (3.93s)1120=== CONT TestPush_RejectsBadRequests11212026/10/01 12:51:05 INFO Received uploads request method=POST path=/api/pending_closures11222026/10/01 12:51:05 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11232026/10/01 12:51:05 INFO Received uploads request method=POST path=/api/pending_closures1124--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.45s)1125=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11262026/10/01 12:51:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11272026/10/01 12:51:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjJhNTNkYzVlLTVmNDItNGMzMC05MmFiLTk0ZGZiYzJhZTg4NngxNzkwODU5MDY0NTczNTIzMDAw parts=1011282026/10/01 12:51:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11292026/10/01 12:51:06 INFO Completed upload id=111302026/10/01 12:51:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011312026/10/01 12:51:06 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/01 12:51:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures11332026/10/01 12:51:06 INFO Aborted multipart uploads count=0 kept=011342026/10/01 12:51:06 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=011352026/10/01 12:51:06 INFO Received uploads request method=POST path=/api/pending_closures11362026/10/01 12:51:06 INFO Vacuumed table table=pending_closures11372026/10/01 12:51:06 INFO Vacuumed table table=pending_objects11382026/10/01 12:51:06 INFO Vacuumed table table=multipart_uploads11392026/10/01 12:51:06 INFO Vacuumed table table=closures11402026/10/01 12:51:06 INFO Vacuumed table table=objects11412026/10/01 12:51:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001142--- PASS: TestService_createPendingClosureHandler (4.15s)1143=== CONT TestPush_CompleteCommitsEveryRoot1144--- PASS: TestConnectWaitsForAPeerMigration (6.08s)1145=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11462026/10/01 12:51:06 INFO Received uploads request method=POST path=/api/pending_closures11472026/10/01 12:51:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11482026/10/01 12:51:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011492026/10/01 12:51:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjA3ODU0Nzg0LWQwNGEtNDI5Yi04MjFhLTQ4MzA3NGJjNTU2ZngxNzkwODU5MDY2NTcyNTE3MDAw11502026/10/01 12:51:06 INFO Received create pin request method=POST path=/api/pins/myapp11512026/10/01 12:51:06 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-75714-2028051062/TestPinProtectsFromGC3022885204/001/store/zilrvbcdyvxng2jz7c9lfxs29di2vzkc-pinned-file.txt narinfo_key=zilrvbcdyvxng2jz7c9lfxs29di2vzkc.narinfo11522026/10/01 12:51:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjA3ODU0Nzg0LWQwNGEtNDI5Yi04MjFhLTQ4MzA3NGJjNTU2ZngxNzkwODU5MDY2NTcyNTE3MDAw parts=111532026/10/01 12:51:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures11542026/10/01 12:51:06 INFO Garbage collection started1155--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.98s)1156=== CONT TestReadRedirectUsesPublicS3URL11572026/10/01 12:51:06 INFO Aborted multipart uploads count=0 kept=011582026/10/01 12:51:06 WARN Force mode enabled - objects will be deleted immediately without grace period11592026/10/01 12:51:06 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=011602026/10/01 12:51:06 INFO Vacuumed table table=pending_closures11612026/10/01 12:51:06 INFO Vacuumed table table=pending_objects11622026/10/01 12:51:06 INFO Vacuumed table table=multipart_uploads11632026/10/01 12:51:06 INFO Vacuumed table table=closures11642026/10/01 12:51:06 INFO Vacuumed table table=objects11652026/10/01 12:51:07 INFO Received uploads request method=POST path=/api/pending_closures11662026/10/01 12:51:07 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/01 12:51:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11682026/10/01 12:51:07 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLmRkOTM2Yjc3LWRlMmUtNGUzMi1hNmVjLTU3ZGMwMzJlYWNlOXgxNzkwODU5MDY2MjQ4MjkzMDAw parts=1211692026/10/01 12:51:07 INFO Received uploads request method=POST path=/api/pending_closures1170--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.06s)1171=== CONT TestReadProxyRangeRequest11722026/10/01 12:51:08 INFO Received push request method=POST path=/api/pushes11732026/10/01 12:51:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11742026/10/01 12:51:08 INFO Signed narinfos id=1 count=11175--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.51s)1176=== CONT TestReadRedirectKeepsNarinfoProxied1177=== RUN TestPush_RejectsBadRequests/no_roots1178=== PAUSE TestPush_RejectsBadRequests/no_roots1179=== RUN TestPush_RejectsBadRequests/no_objects1180=== PAUSE TestPush_RejectsBadRequests/no_objects1181=== RUN TestPush_RejectsBadRequests/bad_root1182=== PAUSE TestPush_RejectsBadRequests/bad_root1183=== RUN TestPush_RejectsBadRequests/root_not_in_objects1184=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1185=== CONT TestCacheConfigHandler1186=== RUN TestCacheConfigHandler/full_config,_no_issuer1187=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1188=== RUN TestCacheConfigHandler/no_cache_url_configured1189=== PAUSE TestCacheConfigHandler/no_cache_url_configured1190=== RUN TestCacheConfigHandler/no_signing_keys1191=== PAUSE TestCacheConfigHandler/no_signing_keys1192=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1193=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1194=== CONT TestClientWithDependencies11952026/10/01 12:51:08 INFO Received push request method=POST path=/api/pushes11962026/10/01 12:51:08 INFO Received complete push request method=POST path=/api/pushes/1/complete11972026/10/01 12:51:08 INFO Received push request method=POST path=/api/pushes11982026/10/01 12:51:08 INFO Aborted multipart uploads count=0 kept=011992026/10/01 12:51:08 WARN Force mode enabled - objects will be deleted immediately without grace period12002026/10/01 12:51:08 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=012012026/10/01 12:51:08 INFO Vacuumed table table=pending_closures1202=== NAME TestPinProtectsFromGC1203 client_integration_test.go:840: Pin successfully protected closure from garbage collection12042026/10/01 12:51:08 INFO Vacuumed table table=pending_objects12052026/10/01 12:51:08 INFO Received push request method=POST path=/api/pushes12062026/10/01 12:51:08 INFO Vacuumed table table=multipart_uploads1207--- PASS: TestPinProtectsFromGC (7.37s)1208=== CONT TestClientMultipleUploads12092026/10/01 12:51:08 INFO Vacuumed table table=closures12102026/10/01 12:51:08 INFO Vacuumed table table=objects12112026/10/01 12:51:08 INFO Received complete push request method=POST path=/api/pushes/2/complete1212--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.91s)1213=== CONT TestClientIntegration12142026/10/01 12:51:08 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/10/01 12:51:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1216--- PASS: TestPush_CompleteCommitsEveryRoot (2.57s)1217=== CONT TestClientErrorHandling1218=== RUN TestClientErrorHandling/InvalidStorePath1219=== PAUSE TestClientErrorHandling/InvalidStorePath1220=== RUN TestClientErrorHandling/InvalidAuthToken1221=== PAUSE TestClientErrorHandling/InvalidAuthToken1222=== RUN TestClientErrorHandling/ServerNotAvailable1223=== PAUSE TestClientErrorHandling/ServerNotAvailable1224=== CONT TestClientCADerivations12252026/10/01 12:51:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjYwZTA5YWUyLTZmYTktNDU4NC04MGIwLTY5Y2UxOTc1MjA4N3gxNzkwODU5MDY3NDczNTQ3MDAw parts=1212262026/10/01 12:51:09 INFO Received uploads request method=POST path=/api/pending_closures12272026/10/01 12:51:09 INFO Received uploads request method=POST path=/api/pending_closures12282026/10/01 12:51:09 INFO Received push request method=POST path=/api/pushes1229--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.77s)1230=== CONT TestCacheStatsHandler1231--- PASS: TestReadRedirectUsesPublicS3URL (2.66s)1232=== CONT TestGCTaskStore_PhaseUpdates1233--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1234=== CONT TestReadProxyDisabled12352026/10/01 12:51:09 WARN Rate limiter enabled after throttle name=s3-test rate=512362026/10/01 12:51:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1237=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1238 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101239 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001240--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.34s)1241=== CONT TestService_readinessHandler1242--- PASS: TestReadProxyRangeRequest (2.06s)1243=== CONT TestReadProxyRootRedirectsToIndexHTML1244--- PASS: TestReadRedirectKeepsNarinfoProxied (1.97s)1245=== CONT TestService_healthCheckHandler1246=== NAME TestClientWithDependencies1247 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-75714-2028051062/TestClientWithDependencies2161493976/001/store/2vv17yq132i7wjnd6ip7mqlkxpm4ja18-test-script1248=== NAME TestClientIntegration1249 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-75714-2028051062/TestClientIntegration3379743570/002/store/15dnl1g6a0ajri0668n4n8pww1p4zrwi-test-file.txt12502026/10/01 12:51:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1251=== NAME TestClientWithDependencies1252 client_integration_test.go:615: Found 1 dependencies (including self)12532026/10/01 12:51:10 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjI3NjU4ZTQ0LTJlNjQtNDk2Yi05ODliLTIyNGJiMjMwNzgwZngxNzkwODU5MDY5MDkxMTI4MDAw error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12542026/10/01 12:51:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWVlMjZlOTMtMGY4OC00OWM4LWIyMGEtYmFmZDgyNTk5MmYxLjBmZjBmZGNhLWM3NGUtNGMyNi05YjBiLTk0MGNkZjQ1MTBlNXgxNzkwODU5MDY5MDY5MjQ2MDAw parts=1212552026/10/01 12:51:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12562026/10/01 12:51:10 INFO Aborted multipart uploads count=1 kept=01257--- PASS: TestRedundantMultipartUpload (6.00s)1258=== CONT TestReadProxyConditionalGet12592026/10/01 12:51:11 INFO Received push request method=POST path=/api/pushes12602026/10/01 12:51:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12612026/10/01 12:51:11 INFO Uploading 15dnl1g6a0ajri0668n4n8pww1p4zrwi-test-file.txt (152B)1262--- PASS: TestCacheStatsHandler (1.87s)1263=== CONT TestGracefulShutdownDrainsInflight12642026/10/01 12:51:11 INFO Starting HTTP server address=127.0.0.1:4943312652026/10/01 12:51:11 INFO Shutdown signal received, draining in-flight requests timeout=10s12662026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12672026/10/01 12:51:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12682026/10/01 12:51:11 WARN Failed to register uploaded object key=15dnl1g6a0ajri0668n4n8pww1p4zrwi.ls error="server returned 404: 404 page not found\n"12692026/10/01 12:51:11 INFO Signed narinfos id=1 count=112702026/10/01 12:51:11 INFO Uploading 1 narinfos12712026/10/01 12:51:11 INFO Received complete push request method=POST path=/api/pushes/1/complete12722026/10/01 12:51:11 WARN Failed to register uploaded object key=15dnl1g6a0ajri0668n4n8pww1p4zrwi.narinfo error="server returned 404: 404 page not found\n"12732026/10/01 12:51:11 INFO Received push request method=POST path=/api/pushes12742026/10/01 12:51:11 INFO Upload complete. (174ms)1275--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1276=== CONT TestGCTaskStore_Fail1277--- PASS: TestGCTaskStore_Fail (0.00s)1278=== CONT TestPresentReportsOnlyClosureRoots12792026/10/01 12:51:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12802026/10/01 12:51:11 INFO Uploading 2vv17yq132i7wjnd6ip7mqlkxpm4ja18-test-script (136B)12812026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12822026/10/01 12:51:11 WARN Failed to register uploaded object key=2vv17yq132i7wjnd6ip7mqlkxpm4ja18.ls error="server returned 404: 404 page not found\n"12832026/10/01 12:51:11 WARN Failed to register uploaded object key=log/2ffg6c6xmpg0m5gca46j7nhrvibva29q-test-script.drv error="server returned 404: 404 page not found\n"12842026/10/01 12:51:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12852026/10/01 12:51:11 INFO Signed narinfos id=1 count=112862026/10/01 12:51:11 INFO Uploading 1 narinfos12872026/10/01 12:51:11 INFO All 1 paths already cached1288=== NAME TestClientIntegration1289 client_integration_test.go:312: Retrieved narinfo from S3:1290 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientIntegration3379743570/002/store/15dnl1g6a0ajri0668n4n8pww1p4zrwi-test-file.txt1291 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1292 Compression: zstd1293 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11294 NarSize: 1521295 References: 1296 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11297 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1298 client_integration_test.go:313: Decompressed .ls content (64 bytes):1299 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1300 client_integration_test.go:316: Testing garbage collection...13012026/10/01 12:51:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13022026/10/01 12:51:11 WARN Failed to register uploaded object key=2vv17yq132i7wjnd6ip7mqlkxpm4ja18.narinfo error="server returned 404: 404 page not found\n"13032026/10/01 12:51:11 INFO Upload complete. (159ms)1304=== NAME TestClientWithDependencies1305 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-75714-2028051062/TestClientWithDependencies2161493976/001/store) requires matching store prefix13062026/10/01 12:51:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures13072026/10/01 12:51:11 INFO Garbage collection started13082026/10/01 12:51:11 INFO Aborted multipart uploads count=0 kept=013092026/10/01 12:51:11 WARN Force mode enabled - objects will be deleted immediately without grace period1310--- PASS: TestClientWithDependencies (2.96s)1311=== CONT TestReadProxyHead13122026/10/01 12:51:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013132026/10/01 12:51:11 INFO Vacuumed table table=pending_closures13142026/10/01 12:51:11 INFO Vacuumed table table=pending_objects13152026/10/01 12:51:11 INFO Vacuumed table table=multipart_uploads13162026/10/01 12:51:11 INFO Vacuumed table table=closures13172026/10/01 12:51:11 INFO Vacuumed table table=objects1318=== NAME TestClientMultipleUploads1319 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-75714-2028051062/TestClientMultipleUploads2954942307/001/store/lh58f8ml8221zjcpcl3awkwz2cd3k66b-test-file-0.txt1320=== NAME TestClientCADerivations1321 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-75714-2028051062/TestClientCADerivations1845505998/001/store/nhr9vjv7s691yz22y98af5aw82wnqmq4-ca-test1322=== NAME TestClientMultipleUploads1323 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-75714-2028051062/TestClientMultipleUploads2954942307/001/store/ki4jpgxalfkv1fzx4gkdmq70g6slcgs0-test-file-1.txt1324--- PASS: TestReadProxyDisabled (2.32s)1325=== CONT TestReadProxyInvalidPath1326=== NAME TestClientCADerivations1327 client_ca_test.go:139: Found 1 dependencies (including self)1328=== NAME TestClientMultipleUploads1329 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-75714-2028051062/TestClientMultipleUploads2954942307/001/store/hn7kvray5l4idwmanydvipznnyzmf5j0-test-file-2.txt13302026/10/01 12:51:11 WARN readiness check failed error="closed pool"1331--- PASS: TestService_readinessHandler (2.33s)1332=== CONT TestReadProxy40413332026/10/01 12:51:11 INFO Received push request method=POST path=/api/pushes13342026/10/01 12:51:11 INFO Received push request method=POST path=/api/pushes13352026/10/01 12:51:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13362026/10/01 12:51:11 INFO Uploading nhr9vjv7s691yz22y98af5aw82wnqmq4-ca-test (144B)13372026/10/01 12:51:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13382026/10/01 12:51:11 INFO Uploading lh58f8ml8221zjcpcl3awkwz2cd3k66b-test-file-0.txt (160B)13392026/10/01 12:51:11 INFO Uploading hn7kvray5l4idwmanydvipznnyzmf5j0-test-file-2.txt (160B)13402026/10/01 12:51:11 INFO Uploading ki4jpgxalfkv1fzx4gkdmq70g6slcgs0-test-file-1.txt (160B)13412026/10/01 12:51:11 WARN Failed to register uploaded object key=nhr9vjv7s691yz22y98af5aw82wnqmq4.ls error="server returned 404: 404 page not found\n"13422026/10/01 12:51:11 WARN Failed to register uploaded object key=log/qilfmkd8wsbd30dz9k2768ln9yf1qgbw-ca-test.drv error="server returned 404: 404 page not found\n"13432026/10/01 12:51:11 WARN Failed to register uploaded object key=hn7kvray5l4idwmanydvipznnyzmf5j0.ls error="server returned 404: 404 page not found\n"13442026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13452026/10/01 12:51:11 WARN Failed to register uploaded object key=lh58f8ml8221zjcpcl3awkwz2cd3k66b.ls error="server returned 404: 404 page not found\n"13462026/10/01 12:51:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13472026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13482026/10/01 12:51:11 WARN Failed to register uploaded object key=ki4jpgxalfkv1fzx4gkdmq70g6slcgs0.ls error="server returned 404: 404 page not found\n"13492026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13502026/10/01 12:51:11 INFO Signed narinfos id=1 count=113512026/10/01 12:51:11 INFO Uploading 1 narinfos13522026/10/01 12:51:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13532026/10/01 12:51:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13542026/10/01 12:51:11 INFO Signed narinfos id=1 count=313552026/10/01 12:51:11 INFO Uploading 3 narinfos13562026/10/01 12:51:12 WARN Failed to register uploaded object key=hn7kvray5l4idwmanydvipznnyzmf5j0.narinfo error="server returned 404: 404 page not found\n"13572026/10/01 12:51:12 WARN Failed to register uploaded object key=ki4jpgxalfkv1fzx4gkdmq70g6slcgs0.narinfo error="server returned 404: 404 page not found\n"13582026/10/01 12:51:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13592026/10/01 12:51:12 WARN Failed to register uploaded object key=nhr9vjv7s691yz22y98af5aw82wnqmq4.narinfo error="server returned 404: 404 page not found\n"13602026/10/01 12:51:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13612026/10/01 12:51:12 WARN Failed to register uploaded object key=lh58f8ml8221zjcpcl3awkwz2cd3k66b.narinfo error="server returned 404: 404 page not found\n"13622026/10/01 12:51:12 INFO Upload complete. (187ms)13632026/10/01 12:51:12 INFO Upload complete. (155ms)1364=== NAME TestClientMultipleUploads1365 client_integration_test.go:369: Uploaded 3 paths in 203.811041ms1366=== NAME TestClientCADerivations1367 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestClientCADerivations1845505998/001/store/nhr9vjv7s691yz22y98af5aw82wnqmq4-ca-test1368 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1369 Compression: zstd1370 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1371 NarSize: 1441372 References: 1373 Deriver: /nix/var/nix/builds/nix-75714-2028051062/TestClientCADerivations1845505998/001/store/qilfmkd8wsbd30dz9k2768ln9yf1qgbw-ca-test.drv1374 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1375 client_ca_test.go:185: Checking for realisation files in S3...1376 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1377 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1378--- PASS: TestClientMultipleUploads (3.23s)1379=== CONT TestReadProxyNarStreaming1380=== NAME TestClientCADerivations1381 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket50?endpoint=http://localhost:49204®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-75714-2028051062/TestClientCADerivations1845505998/001/store'1382 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11383--- PASS: TestClientCADerivations (3.20s)1384=== CONT TestReadProxyNarinfoAlreadyDecompressed1385--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.37s)1386=== CONT TestReadProxyNarinfo1387--- PASS: TestService_healthCheckHandler (2.27s)1388=== CONT TestIsValidCachePath1389=== RUN TestIsValidCachePath/narinfo1390=== PAUSE TestIsValidCachePath/narinfo1391=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1392=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1393=== RUN TestIsValidCachePath/nar_zst1394=== PAUSE TestIsValidCachePath/nar_zst1395=== RUN TestIsValidCachePath/nar_xz1396=== PAUSE TestIsValidCachePath/nar_xz1397=== RUN TestIsValidCachePath/nar_bz21398=== PAUSE TestIsValidCachePath/nar_bz21399=== RUN TestIsValidCachePath/nar_uncompressed1400=== PAUSE TestIsValidCachePath/nar_uncompressed1401=== RUN TestIsValidCachePath/ls1402=== PAUSE TestIsValidCachePath/ls1403=== RUN TestIsValidCachePath/log1404=== PAUSE TestIsValidCachePath/log1405=== RUN TestIsValidCachePath/realisation1406=== PAUSE TestIsValidCachePath/realisation1407=== RUN TestIsValidCachePath/nix-cache-info1408=== PAUSE TestIsValidCachePath/nix-cache-info1409=== RUN TestIsValidCachePath/index.html1410=== PAUSE TestIsValidCachePath/index.html1411=== RUN TestIsValidCachePath/traversal_parent1412=== PAUSE TestIsValidCachePath/traversal_parent1413=== RUN TestIsValidCachePath/traversal_in_middle1414=== PAUSE TestIsValidCachePath/traversal_in_middle1415=== RUN TestIsValidCachePath/invalid_char_e1416=== PAUSE TestIsValidCachePath/invalid_char_e1417=== RUN TestIsValidCachePath/invalid_char_u1418=== PAUSE TestIsValidCachePath/invalid_char_u1419=== RUN TestIsValidCachePath/random_path1420=== PAUSE TestIsValidCachePath/random_path1421=== RUN TestIsValidCachePath/empty1422=== PAUSE TestIsValidCachePath/empty1423=== RUN TestIsValidCachePath/leading_slash1424=== PAUSE TestIsValidCachePath/leading_slash1425=== RUN TestIsValidCachePath/wrong_extension1426=== PAUSE TestIsValidCachePath/wrong_extension1427=== RUN TestIsValidCachePath/short_hash1428=== PAUSE TestIsValidCachePath/short_hash1429=== CONT TestProxyHeadersOnlyTrustedOnSocket1430--- PASS: TestReadProxyConditionalGet (1.50s)1431=== CONT TestParseSingleRange1432=== RUN TestParseSingleRange/none1433=== PAUSE TestParseSingleRange/none1434=== RUN TestParseSingleRange/unknown_unit1435=== PAUSE TestParseSingleRange/unknown_unit1436=== RUN TestParseSingleRange/multi-range_ignored1437=== PAUSE TestParseSingleRange/multi-range_ignored1438=== RUN TestParseSingleRange/malformed_no_dash1439=== PAUSE TestParseSingleRange/malformed_no_dash1440=== RUN TestParseSingleRange/malformed_both_empty1441=== PAUSE TestParseSingleRange/malformed_both_empty1442=== RUN TestParseSingleRange/malformed_end_before_start1443=== PAUSE TestParseSingleRange/malformed_end_before_start1444=== RUN TestParseSingleRange/closed1445=== PAUSE TestParseSingleRange/closed1446=== RUN TestParseSingleRange/open-ended1447=== PAUSE TestParseSingleRange/open-ended1448=== RUN TestParseSingleRange/end_clamped_to_size1449=== PAUSE TestParseSingleRange/end_clamped_to_size1450=== RUN TestParseSingleRange/suffix1451=== PAUSE TestParseSingleRange/suffix1452=== RUN TestParseSingleRange/suffix_exceeds_size1453=== PAUSE TestParseSingleRange/suffix_exceeds_size1454=== RUN TestParseSingleRange/single_byte1455=== PAUSE TestParseSingleRange/single_byte1456=== RUN TestParseSingleRange/start_past_EOF1457=== PAUSE TestParseSingleRange/start_past_EOF1458=== RUN TestParseSingleRange/start_far_past_EOF1459=== PAUSE TestParseSingleRange/start_far_past_EOF1460=== CONT TestPresentNotReportedWhileGCDeletesClosure1461--- PASS: TestReadProxyHead (1.52s)1462=== CONT TestGCTaskStore_GetEmpty1463--- PASS: TestGCTaskStore_GetEmpty (0.00s)1464=== CONT TestGCTaskStore_CompletedAllowsNewTask1465--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1466=== CONT TestGCTaskStore_GetReturnsLatest1467--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1468=== CONT TestService_AuthMiddleware_OIDC14692026/10/01 12:51:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49498/oidc1470--- PASS: TestPresentReportsOnlyClosureRoots (1.95s)1471=== CONT TestService_ReadScope_PublicByDefault14722026/10/01 12:51:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01473=== NAME TestClientIntegration1474 client_integration_test.go:323: Objects in database after GC:1475 client_integration_test.go:323: Successfully deleted all objects with GC --force1476--- PASS: TestClientIntegration (4.37s)1477=== CONT TestService_RequireScope_OIDC1478--- PASS: TestReadProxyInvalidPath (1.52s)1479=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14802026/10/01 12:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49506/oidc1481--- PASS: TestReadProxy404 (1.64s)1482=== CONT TestService_ReadAuthMiddleware1483--- PASS: TestReadProxyNarStreaming (1.68s)1484=== CONT TestGCTaskStore_ConflictDifferentParams1485--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1486=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14872026/10/01 12:51:14 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"14882026/10/01 12:51:14 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161489--- PASS: TestReadProxyNarinfo (2.19s)1490=== CONT TestCreatePin_ReservedPins1491--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.22s)1492=== CONT TestOrphanedObjectsGCStressTest14932026/10/01 12:51:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49526/oidc14942026/10/01 12:51:14 INFO Starting HTTP server address=/nix/var/nix/builds/nix-75714-2028051062/TestProxyHeadersOnlyTrustedOnSocket457359785/001/proxy.sock14952026/10/01 12:51:14 INFO Starting HTTP server address=127.0.0.1:4952814962026/10/01 12:51:14 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14972026/10/01 12:51:14 INFO Shutdown signal received, draining in-flight requests timeout=10s1498--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.26s)1499=== CONT TestOrphanedObjectsGC1500=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1501=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1502=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1503=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1504=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1505=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1506=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1507=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1508=== CONT TestObjectStatsTrigger1509--- PASS: TestService_ReadScope_PublicByDefault (2.11s)1510=== CONT TestPendingCleanupUsesOneCutoff1511--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.79s)1512=== CONT TestGCTaskStore_DeduplicateSameParams1513--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1514=== CONT TestService_NativeMTLS15152026/10/01 12:51:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15162026/10/01 12:51:15 WARN mTLS auth: bound subjects configured but subject DN unavailable15172026/10/01 12:51:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1518--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.08s)1519=== CONT TestMultipartCleanup1520=== RUN TestService_RequireScope_OIDC/builder_may_write1521=== PAUSE TestService_RequireScope_OIDC/builder_may_write1522=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1523=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1524=== RUN TestService_RequireScope_OIDC/ops_may_admin1525=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1526=== RUN TestService_RequireScope_OIDC/ops_may_not_write1527=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1528=== RUN TestService_RequireScope_OIDC/reader_may_not_write1529=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1530=== RUN TestService_RequireScope_OIDC/static_token_may_admin1531=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1532=== RUN TestService_RequireScope_OIDC/static_token_may_write1533=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1534=== RUN TestService_RequireScope_OIDC/reader_may_read1535=== PAUSE TestService_RequireScope_OIDC/reader_may_read1536=== RUN TestService_RequireScope_OIDC/writer_implies_read1537=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1538=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1539=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1540=== CONT TestServerTLSConfig1541=== RUN TestServerTLSConfig/no_client_CA1542=== PAUSE TestServerTLSConfig/no_client_CA1543=== RUN TestServerTLSConfig/missing_CA_file1544=== PAUSE TestServerTLSConfig/missing_CA_file1545=== RUN TestServerTLSConfig/not_a_PEM_file1546=== PAUSE TestServerTLSConfig/not_a_PEM_file1547=== CONT TestService_AuthMiddleware_MTLSProxyHeader15482026/10/01 12:51:15 INFO Received uploads request method=POST path=/api/pending_closures1549--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.11s)1550=== CONT TestMetricsInventory1551--- PASS: TestService_ReadAuthMiddleware (2.43s)1552=== CONT TestNARDeduplicationMetadataUploadBug15532026/10/01 12:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15542026/10/01 12:51:16 WARN Refused reserved pin name=worker-x86_64-linux15552026/10/01 12:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15562026/10/01 12:51:16 INFO Received create pin request method=POST path=/api/pins/my-app15572026/10/01 12:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1558--- PASS: TestCreatePin_ReservedPins (2.27s)1559=== CONT TestReadProxyOutlastsServerWriteTimeout1560--- PASS: TestObjectStatsTrigger (1.96s)1561=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1562=== NAME TestOrphanedObjectsGC1563 orphaned_objects_gc_test.go:290: GC Test Summary:1564 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1565 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1566 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1567 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1568 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1569--- PASS: TestOrphanedObjectsGC (2.53s)1570=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15712026/10/01 12:51:17 INFO Received uploads request method=POST path=/api/pending_closures15722026/10/01 12:51:17 INFO Received uploads request method=POST path=/api/pending_closures15732026/10/01 12:51:17 INFO Received cleanup request method=DELETE path=/api/pending_closures15742026/10/01 12:51:17 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/01 12:51:17 INFO Received cleanup request method=DELETE path=/api/pending_closures15762026/10/01 12:51:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket77/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15772026/10/01 12:51:17 INFO Aborted multipart uploads count=0 kept=115782026/10/01 12:51:17 INFO Received cleanup request method=DELETE path=/api/pending_closures15792026/10/01 12:51:17 INFO Aborted multipart uploads count=1 kept=01580--- PASS: TestMultipartCleanup (2.37s)1581=== CONT TestResolveDBConnectionString/flag_wins1582=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1583=== CONT TestResolveDBConnectionString/nothing_configured1584=== CONT TestResolveDBConnectionString/missing_file_is_an_error1585=== CONT TestResolveDBConnectionString/file_when_flag_empty1586=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15872026/10/01 12:51:17 INFO Received uploads request method=POST path=/1588--- PASS: TestResolveDBConnectionString (0.01s)1589 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1590 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1591 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1592 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1593 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15942026/10/01 12:51:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15952026/10/01 12:51:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1596--- PASS: TestService_NativeMTLS (2.51s)1597=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15982026/10/01 12:51:17 INFO Received request for more parts method=POST path=/1599=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16002026/10/01 12:51:17 INFO Received complete multipart upload request method=POST path=/1601=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16022026/10/01 12:51:17 INFO Received uploads request method=POST path=/1603=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16042026/10/01 12:51:17 INFO Received complete multipart upload request method=POST path=/1605=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16062026/10/01 12:51:17 INFO Received request for more parts method=POST path=/1607=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16082026/10/01 12:51:17 INFO Received uploads request method=POST path=/1609--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1610 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1611 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1612 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1613 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1614=== CONT TestIsValidUploadKey/narinfo1615=== CONT TestIsValidUploadKey/realisation_plus_in_output1616=== CONT TestIsValidUploadKey/unknown_type1617=== CONT TestIsValidUploadKey/empty_key1618=== CONT TestIsValidUploadKey/absolute1619=== CONT TestIsValidUploadKey/traversal_nar1620=== CONT TestIsValidUploadKey/traversal1621=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1622=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1623=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1624=== CONT TestIsValidUploadKey/index.html1625=== CONT TestIsValidUploadKey/nix-cache-info1626=== CONT TestIsValidUploadKey/build_log_home-manager_file1627=== CONT TestIsValidUploadKey/realisation1628=== CONT TestIsValidUploadKey/build_log_equals1629=== CONT TestIsValidUploadKey/build_log_question_mark1630=== CONT TestIsValidUploadKey/build_log_plus_in_name1631=== CONT TestIsValidUploadKey/nar_plain1632=== CONT TestIsValidUploadKey/build_log1633=== CONT TestIsValidUploadKey/listing1634=== CONT TestIsValidUploadKey/nar_xz1635=== CONT TestIsValidUploadKey/nar_zst1636--- PASS: TestIsValidUploadKey (0.00s)1637 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1638 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1639 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1640 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1641 --- PASS: TestIsValidUploadKey/absolute (0.00s)1642 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1643 --- PASS: TestIsValidUploadKey/traversal (0.00s)1644 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1645 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1646 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1647 --- PASS: TestIsValidUploadKey/index.html (0.00s)1648 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1649 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1650 --- PASS: TestIsValidUploadKey/realisation (0.00s)1651 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1652 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1653 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1654 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1655 --- PASS: TestIsValidUploadKey/build_log (0.00s)1656 --- PASS: TestIsValidUploadKey/listing (0.00s)1657 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1658 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1659=== CONT TestPendingClosureWriteTimeout/empty1660=== CONT TestPendingClosureWriteTimeout/670k_objects1661=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1662--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.52s)1663=== CONT TestPendingClosureWriteTimeout/400_objects1664=== CONT TestProxyWriteTimeout/narinfo1665=== CONT TestProxyWriteTimeout/10_GiB_nar1666=== CONT TestProxyWriteTimeout/unknown_size1667=== CONT TestProxyWriteTimeout/1_GiB_nar1668--- PASS: TestProxyWriteTimeout (0.00s)1669 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1670 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1671 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1672 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1673=== CONT TestPush_RejectsBadRequests/no_roots16742026/10/01 12:51:18 INFO Received push request method=POST path=/api/pushes1675=== CONT TestPush_RejectsBadRequests/bad_root16762026/10/01 12:51:18 INFO Received push request method=POST path=/api/pushes1677=== CONT TestPush_RejectsBadRequests/root_not_in_objects16782026/10/01 12:51:18 INFO Received push request method=POST path=/api/pushes1679=== CONT TestPush_RejectsBadRequests/no_objects16802026/10/01 12:51:18 INFO Received push request method=POST path=/api/pushes1681--- PASS: TestPush_RejectsBadRequests (2.43s)1682 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1683 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1684 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1685 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1686=== CONT TestCacheConfigHandler/full_config,_no_issuer1687=== CONT TestCacheConfigHandler/no_signing_keys1688=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1689=== CONT TestCacheConfigHandler/no_cache_url_configured1690--- PASS: TestCacheConfigHandler (0.00s)1691 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1692 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1693 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1694 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1695=== CONT TestClientErrorHandling/InvalidStorePath1696--- PASS: TestMetricsInventory (2.66s)1697=== CONT TestClientErrorHandling/ServerNotAvailable1698=== CONT TestClientErrorHandling/InvalidAuthToken1699--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1700 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1701 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1702 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.78s)17032026/10/01 12:51:18 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/present17042026/10/01 12:51:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.666341ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1705=== NAME TestNARDeduplicationMetadataUploadBug1706 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-75714-2028051062/TestNARDeduplicationMetadataUploadBug788243937/001/store/v3sfma02v9apmqycghndwgmpl1i1i5c6-file1.txt17072026/10/01 12:51:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.43937ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17082026/10/01 12:51:19 INFO Received push request method=POST path=/api/pushes17092026/10/01 12:51:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17102026/10/01 12:51:19 INFO Uploading v3sfma02v9apmqycghndwgmpl1i1i5c6-file1.txt (160B)17112026/10/01 12:51:19 WARN Failed to register uploaded object key=v3sfma02v9apmqycghndwgmpl1i1i5c6.ls error="server returned 404: 404 page not found\n"17122026/10/01 12:51:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17132026/10/01 12:51:19 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17142026/10/01 12:51:19 INFO Signed narinfos id=1 count=117152026/10/01 12:51:19 INFO Uploading 1 narinfos17162026/10/01 12:51:19 INFO Received complete push request method=POST path=/api/pushes/1/complete17172026/10/01 12:51:19 WARN Failed to register uploaded object key=v3sfma02v9apmqycghndwgmpl1i1i5c6.narinfo error="server returned 404: 404 page not found\n"17182026/10/01 12:51:19 INFO Upload complete. (217ms)1719 metadata_upload_test.go:54: Retrieved narinfo from S3:1720 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestNARDeduplicationMetadataUploadBug788243937/001/store/v3sfma02v9apmqycghndwgmpl1i1i5c6-file1.txt1721 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1722 Compression: zstd1723 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1724 NarSize: 1601725 References: 1726 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1727 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1728 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1729 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17302026/10/01 12:51:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=765.699211ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1731 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-75714-2028051062/TestNARDeduplicationMetadataUploadBug788243937/001/store/bfhy1wyry759m5vbqd33dji0lmfkzg9i-file2.txt17322026/10/01 12:51:19 INFO Received uploads request method=POST path=/api/pending_closures17332026/10/01 12:51:19 INFO Aborted multipart uploads count=0 kept=017342026/10/01 12:51:19 WARN Force mode enabled - objects will be deleted immediately without grace period17352026/10/01 12:51:19 INFO Received push request method=POST path=/api/pushes17362026/10/01 12:51:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17372026/10/01 12:51:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17382026/10/01 12:51:19 INFO Signed narinfos id=2 count=117392026/10/01 12:51:19 WARN Failed to register uploaded object key=bfhy1wyry759m5vbqd33dji0lmfkzg9i.ls error="server returned 404: 404 page not found\n"17402026/10/01 12:51:19 INFO Uploading 1 narinfos17412026/10/01 12:51:19 INFO Received complete push request method=POST path=/api/pushes/2/complete17422026/10/01 12:51:19 WARN Failed to register uploaded object key=bfhy1wyry759m5vbqd33dji0lmfkzg9i.narinfo error="server returned 404: 404 page not found\n"17432026/10/01 12:51:19 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=017442026/10/01 12:51:19 INFO Upload complete. (147ms)17452026/10/01 12:51:19 INFO Vacuumed table table=pending_closures1746 metadata_upload_test.go:76: Retrieved narinfo from S3:1747 StorePath: /nix/var/nix/builds/nix-75714-2028051062/TestNARDeduplicationMetadataUploadBug788243937/001/store/bfhy1wyry759m5vbqd33dji0lmfkzg9i-file2.txt1748 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1749 Compression: zstd1750 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1751 NarSize: 1601752 References: 1753 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17542026/10/01 12:51:19 INFO Vacuumed table table=pending_objects17552026/10/01 12:51:19 INFO Vacuumed table table=multipart_uploads17562026/10/01 12:51:19 INFO Vacuumed table table=closures1757 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1758 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1759 {"version":1,"root":{"type":"regular","size":44}}17602026/10/01 12:51:19 INFO Vacuumed table table=objects1761--- PASS: TestNARDeduplicationMetadataUploadBug (3.80s)1762=== CONT TestIsValidCachePath/narinfo1763=== CONT TestIsValidCachePath/index.html1764=== CONT TestIsValidCachePath/short_hash1765=== CONT TestIsValidCachePath/wrong_extension1766=== CONT TestIsValidCachePath/leading_slash1767=== CONT TestIsValidCachePath/empty1768=== CONT TestIsValidCachePath/random_path1769=== CONT TestIsValidCachePath/invalid_char_u1770=== CONT TestIsValidCachePath/invalid_char_e1771=== CONT TestIsValidCachePath/traversal_in_middle1772=== CONT TestIsValidCachePath/traversal_parent1773=== CONT TestIsValidCachePath/nar_uncompressed1774=== CONT TestIsValidCachePath/nix-cache-info1775=== CONT TestIsValidCachePath/realisation1776=== CONT TestIsValidCachePath/log1777=== CONT TestIsValidCachePath/ls1778=== CONT TestIsValidCachePath/nar_xz1779=== CONT TestIsValidCachePath/nar_bz21780=== CONT TestIsValidCachePath/nar_zst1781=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1782--- PASS: TestIsValidCachePath (0.00s)1783 --- PASS: TestIsValidCachePath/narinfo (0.00s)1784 --- PASS: TestIsValidCachePath/index.html (0.00s)1785 --- PASS: TestIsValidCachePath/short_hash (0.00s)1786 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1787 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1788 --- PASS: TestIsValidCachePath/empty (0.00s)1789 --- PASS: TestIsValidCachePath/random_path (0.00s)1790 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1791 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1792 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1793 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1794 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1795 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1796 --- PASS: TestIsValidCachePath/realisation (0.00s)1797 --- PASS: TestIsValidCachePath/log (0.00s)1798 --- PASS: TestIsValidCachePath/ls (0.00s)1799 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1800 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1801 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1802 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1803=== CONT TestParseSingleRange/none1804=== CONT TestParseSingleRange/suffix_exceeds_size1805=== CONT TestParseSingleRange/suffix1806=== CONT TestParseSingleRange/end_clamped_to_size1807=== CONT TestParseSingleRange/open-ended1808=== CONT TestParseSingleRange/closed1809=== CONT TestParseSingleRange/malformed_end_before_start1810=== CONT TestParseSingleRange/malformed_both_empty1811=== CONT TestParseSingleRange/malformed_no_dash1812=== CONT TestParseSingleRange/multi-range_ignored1813=== CONT TestParseSingleRange/unknown_unit1814=== CONT TestParseSingleRange/start_far_past_EOF1815=== CONT TestParseSingleRange/single_byte1816=== CONT TestParseSingleRange/start_past_EOF1817--- PASS: TestParseSingleRange (0.00s)1818 --- PASS: TestParseSingleRange/none (0.00s)1819 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1820 --- PASS: TestParseSingleRange/suffix (0.00s)1821 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1822 --- PASS: TestParseSingleRange/open-ended (0.00s)1823 --- PASS: TestParseSingleRange/closed (0.00s)1824 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1825 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1826 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1827 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1828 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1829 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1830 --- PASS: TestParseSingleRange/single_byte (0.00s)1831 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1832=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1833=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18342026/10/01 12:51:19 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]1835=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1836=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18372026/10/01 12:51:19 WARN Authentication failed token_preview=eyJhbGciOi...wPV4NFiaAg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1838--- PASS: TestService_AuthMiddleware_OIDC (2.21s)1839 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1840 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1841 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1842 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1843=== CONT TestService_RequireScope_OIDC/builder_may_write1844=== CONT TestService_RequireScope_OIDC/static_token_may_admin1845=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1846=== CONT TestService_RequireScope_OIDC/writer_implies_read1847=== CONT TestService_RequireScope_OIDC/reader_may_read1848=== CONT TestService_RequireScope_OIDC/static_token_may_write1849=== CONT TestService_RequireScope_OIDC/ops_may_not_write1850=== CONT TestService_RequireScope_OIDC/reader_may_not_write1851=== CONT TestService_RequireScope_OIDC/ops_may_admin1852=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1853=== CONT TestServerTLSConfig/no_client_CA1854=== CONT TestServerTLSConfig/missing_CA_file1855=== CONT TestServerTLSConfig/not_a_PEM_file1856--- PASS: TestServerTLSConfig (0.00s)1857 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1858 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1859 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1860--- PASS: TestService_RequireScope_OIDC (2.38s)1861 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1862 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1863 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1864 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1865 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1866 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1867 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1868 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1869 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1870 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18712026/10/01 12:51:20 INFO Received uploads request method=POST path=/api/pending_closures18722026/10/01 12:51:20 INFO Aborted multipart uploads count=0 kept=018732026/10/01 12:51:20 WARN Force mode enabled - objects will be deleted immediately without grace period18742026/10/01 12:51:20 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=018752026/10/01 12:51:20 INFO Vacuumed table table=pending_closures18762026/10/01 12:51:20 INFO Vacuumed table table=pending_objects18772026/10/01 12:51:20 INFO Vacuumed table table=multipart_uploads18782026/10/01 12:51:20 INFO Vacuumed table table=closures18792026/10/01 12:51:20 INFO Vacuumed table table=objects1880--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1881 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.92s)1882 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.97s)18832026/10/01 12:51:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.508418633s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18842026/10/01 12:51:20 INFO Received uploads request method=POST path=/api/pending_closures18852026/10/01 12:51:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18862026/10/01 12:51:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1887--- PASS: TestPendingClosureWriteTimeout (0.00s)1888 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1889 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1890 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1891 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.19s)1892=== NAME TestOrphanedObjectsGCStressTest1893 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1894 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18952026/10/01 12:51:21 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-config18962026/10/01 12:51:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.269072ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1897 orphaned_objects_gc_test.go:509: Stress test completed successfully:1898 orphaned_objects_gc_test.go:510: - Active objects preserved: 201899 orphaned_objects_gc_test.go:511: - Objects deleted: 2101900 orphaned_objects_gc_test.go:512: - Total GC'd: 2101901--- PASS: TestOrphanedObjectsGCStressTest (7.69s)19022026/10/01 12:51:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.448324ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19032026/10/01 12:51:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=723.951847ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19042026/10/01 12:51:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.679258034s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19052026/10/01 12:51:23 INFO Aborted multipart uploads count=1 kept=019062026/10/01 12:51:23 INFO Received cleanup request method=DELETE path=/api/pending_closures19072026/10/01 12:51:23 INFO Aborted multipart uploads count=1 kept=01908--- PASS: TestPendingCleanupUsesOneCutoff (8.16s)1909--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.91s)19102026/10/01 12:51:24 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"19112026/10/01 12:51:24 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-config19122026/10/01 12:51:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.278405ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19132026/10/01 12:51:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.745418ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19142026/10/01 12:51:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.534716ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19152026/10/01 12:51:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746496126s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19162026/10/01 12:51:28 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_closures19172026/10/01 12:51:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.269686ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19182026/10/01 12:51:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.363377ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19192026/10/01 12:51:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.018325ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19202026/10/01 12:51:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.682619749s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1921--- PASS: TestClientErrorHandling (0.00s)1922 --- PASS: TestClientErrorHandling/InvalidStorePath (2.41s)1923 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.47s)1924 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.76s)1925PASS1926{"timestamp":"2026-10-01T12:51:31.265424Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49367","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}19272026-10-01 12:51:31.381 UTC [76617] LOG: received smart shutdown request19282026-10-01 12:51:31.383 UTC [76617] LOG: background worker "logical replication launcher" (PID 76627) exited with exit code 119292026-10-01 12:51:31.391 UTC [76622] LOG: shutting down19302026-10-01 12:51:31.392 UTC [76622] LOG: checkpoint starting: shutdown immediate19312026-10-01 12:51:32.637 UTC [76622] LOG: checkpoint complete: wrote 12738 buffers (77.7%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.677 s, sync=0.535 s, total=1.246 s; sync files=29655, longest=0.001 s, average=0.001 s; distance=417229 kB, estimate=417229 kB; lsn=0/1AF004F0, redo lsn=0/1AF004F019322026-10-01 12:51:32.644 UTC [76617] LOG: database system is shut down1933Running OIDC tests...1934=== RUN TestAudienceForIssuer1935=== PAUSE TestAudienceForIssuer1936=== RUN TestGlobMatch1937=== PAUSE TestGlobMatch1938=== RUN TestValidateToken_ValidToken1939=== PAUSE TestValidateToken_ValidToken1940=== RUN TestValidateToken_WrongAudience1941=== PAUSE TestValidateToken_WrongAudience1942=== RUN TestValidateToken_Expired1943=== PAUSE TestValidateToken_Expired1944=== RUN TestValidateToken_BoundClaimsMismatch1945=== PAUSE TestValidateToken_BoundClaimsMismatch1946=== RUN TestValidateToken_BoundSubjectMismatch1947=== PAUSE TestValidateToken_BoundSubjectMismatch1948=== RUN TestValidateToken_MultipleProviders1949=== PAUSE TestValidateToken_MultipleProviders1950=== RUN TestValidateToken_NoMatchingProvider1951=== PAUSE TestValidateToken_NoMatchingProvider1952=== RUN TestValidateToken_KubernetesServiceAccount1953=== PAUSE TestValidateToken_KubernetesServiceAccount1954=== RUN TestNewValidator_KubernetesRequiresCA1955=== PAUSE TestNewValidator_KubernetesRequiresCA1956=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1957=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1958=== RUN TestPins_ReservedForMatchingRule1959=== PAUSE TestPins_ReservedForMatchingRule1960=== RUN TestPins_TopLevelShorthand1961=== PAUSE TestPins_TopLevelShorthand1962=== RUN TestPins_ConfigValidation1963=== PAUSE TestPins_ConfigValidation1964=== RUN TestScopes_LegacyProviderDefaultsToWrite1965=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1966=== RUN TestScopes_Rules1967=== PAUSE TestScopes_Rules1968=== RUN TestScopes_ConfigValidation1969=== PAUSE TestScopes_ConfigValidation1970=== CONT TestAudienceForIssuer1971--- PASS: TestAudienceForIssuer (0.00s)1972=== CONT TestValidateToken_NoMatchingProvider1973=== CONT TestValidateToken_Expired1974=== CONT TestValidateToken_KubernetesServiceAccount1975=== CONT TestPins_ConfigValidation1976=== CONT TestPins_ReservedForMatchingRule1977=== CONT TestValidateToken_KubernetesIssuerFromOwnToken1978=== CONT TestNewValidator_KubernetesRequiresCA1979=== CONT TestValidateToken_BoundSubjectMismatch1980=== CONT TestValidateToken_MultipleProviders1981--- PASS: TestPins_ConfigValidation (0.00s)1982=== CONT TestScopes_ConfigValidation1983=== CONT TestScopes_Rules1984--- PASS: TestScopes_ConfigValidation (0.00s)1985=== CONT TestScopes_LegacyProviderDefaultsToWrite19862026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49654/oidc1987--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)1988=== CONT TestValidateToken_WrongAudience19892026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49658/oidc19902026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49656/oidc1991--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)1992=== CONT TestValidateToken_ValidToken1993--- PASS: TestValidateToken_Expired (0.05s)1994=== CONT TestGlobMatch1995=== RUN TestGlobMatch/foo_foo1996=== PAUSE TestGlobMatch/foo_foo1997=== RUN TestGlobMatch/foo_bar1998=== PAUSE TestGlobMatch/foo_bar1999=== RUN TestGlobMatch/*_2000=== PAUSE TestGlobMatch/*_2001=== RUN TestGlobMatch/*_anything2002=== PAUSE TestGlobMatch/*_anything2003=== RUN TestGlobMatch/foo*_foo2004=== PAUSE TestGlobMatch/foo*_foo2005=== RUN TestGlobMatch/foo*_foobar2006=== PAUSE TestGlobMatch/foo*_foobar2007=== RUN TestGlobMatch/foo*_bar2008=== PAUSE TestGlobMatch/foo*_bar2009=== RUN TestGlobMatch/*bar_bar2010=== PAUSE TestGlobMatch/*bar_bar2011=== RUN TestGlobMatch/*bar_foobar2012=== PAUSE TestGlobMatch/*bar_foobar2013=== RUN TestGlobMatch/*bar_foo2014=== PAUSE TestGlobMatch/*bar_foo2015=== RUN TestGlobMatch/foo*bar_foobar2016=== PAUSE TestGlobMatch/foo*bar_foobar2017=== RUN TestGlobMatch/foo*bar_foo123bar2018=== PAUSE TestGlobMatch/foo*bar_foo123bar2019=== RUN TestGlobMatch/foo*bar_foobarbaz2020=== PAUSE TestGlobMatch/foo*bar_foobarbaz2021=== RUN TestGlobMatch/*/*_foo/bar2022=== PAUSE TestGlobMatch/*/*_foo/bar2023=== RUN TestGlobMatch/*/*_foo2024=== PAUSE TestGlobMatch/*/*_foo2025=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2026=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2027=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02028=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02029=== RUN TestGlobMatch/refs/*/main_refs/heads/main2030=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2031=== RUN TestGlobMatch/fo?_foo2032=== PAUSE TestGlobMatch/fo?_foo2033=== RUN TestGlobMatch/fo?_fo2034=== PAUSE TestGlobMatch/fo?_fo2035=== RUN TestGlobMatch/fo?_fooo2036=== PAUSE TestGlobMatch/fo?_fooo2037=== RUN TestGlobMatch/?oo_foo2038=== PAUSE TestGlobMatch/?oo_foo2039=== RUN TestGlobMatch/?oo_boo2040=== PAUSE TestGlobMatch/?oo_boo2041=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2042=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2043=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2044=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2045=== CONT TestValidateToken_BoundClaimsMismatch20462026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49660/oidc2047--- PASS: TestPins_ReservedForMatchingRule (0.07s)2048=== CONT TestPins_TopLevelShorthand20492026/10/01 12:51:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49662/oidc20502026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49664/oidc2051--- PASS: TestValidateToken_WrongAudience (0.07s)2052--- PASS: TestValidateToken_NoMatchingProvider (0.10s)2053=== CONT TestGlobMatch/foo_foo2054=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2055=== CONT TestGlobMatch/?oo_boo2056=== CONT TestGlobMatch/?oo_foo2057=== CONT TestGlobMatch/fo?_fooo2058=== CONT TestGlobMatch/fo?_fo2059=== CONT TestGlobMatch/fo?_foo2060=== CONT TestGlobMatch/refs/*/main_refs/heads/main2061=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02062=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2063=== CONT TestGlobMatch/*/*_foo2064=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2065=== CONT TestGlobMatch/foo*bar_foobarbaz2066=== CONT TestGlobMatch/foo*bar_foo123bar2067=== CONT TestGlobMatch/foo*bar_foobar2068=== CONT TestGlobMatch/*bar_foo2069=== CONT TestGlobMatch/*bar_foobar2070=== CONT TestGlobMatch/*/*_foo/bar2071=== CONT TestGlobMatch/foo*_bar2072=== CONT TestGlobMatch/foo*_foobar2073=== CONT TestGlobMatch/foo*_foo2074=== CONT TestGlobMatch/*_anything2075=== CONT TestGlobMatch/*_2076=== CONT TestGlobMatch/*bar_bar2077=== CONT TestGlobMatch/foo_bar2078--- PASS: TestGlobMatch (0.00s)2079 --- PASS: TestGlobMatch/foo_foo (0.00s)2080 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2081 --- PASS: TestGlobMatch/?oo_boo (0.00s)2082 --- PASS: TestGlobMatch/?oo_foo (0.00s)2083 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2084 --- PASS: TestGlobMatch/fo?_fo (0.00s)2085 --- PASS: TestGlobMatch/fo?_foo (0.00s)2086 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2087 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2088 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2089 --- PASS: TestGlobMatch/*/*_foo (0.00s)2090 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2091 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2092 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2093 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2094 --- PASS: TestGlobMatch/*bar_foo (0.00s)2095 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2096 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2097 --- PASS: TestGlobMatch/foo*_bar (0.00s)2098 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2099 --- PASS: TestGlobMatch/foo*_foo (0.00s)2100 --- PASS: TestGlobMatch/*_anything (0.00s)2101 --- PASS: TestGlobMatch/*_ (0.00s)2102 --- PASS: TestGlobMatch/*bar_bar (0.00s)2103 --- PASS: TestGlobMatch/foo_bar (0.00s)21042026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49668/oidc2105--- PASS: TestPins_TopLevelShorthand (0.04s)21062026/10/01 12:51:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49663/oidc21072026/10/01 12:51:34 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49670/oidc21082026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49673/oidc2109--- PASS: TestValidateToken_MultipleProviders (0.12s)2110--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)21112026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49675/oidc2112--- PASS: TestValidateToken_ValidToken (0.09s)21132026/10/01 12:51:34 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:496772114--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)21152026/10/01 12:51:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49679/oidc21162026/10/01 12:51:34 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232117--- PASS: TestScopes_Rules (0.16s)2118--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)21192026/10/01 12:51:34 http: TLS handshake error from 127.0.0.1:49684: remote error: tls: bad certificate2120--- PASS: TestNewValidator_KubernetesRequiresCA (0.23s)2121PASS2122Running hook tests...2123=== RUN TestSendPathsEmpty2124=== PAUSE TestSendPathsEmpty2125=== RUN TestQueueEnqueueAndFetch2126=== PAUSE TestQueueEnqueueAndFetch2127=== RUN TestQueueDeduplication2128=== PAUSE TestQueueDeduplication2129=== RUN TestQueueRemove2130=== PAUSE TestQueueRemove2131=== RUN TestQueueFetchBatchLimit2132=== PAUSE TestQueueFetchBatchLimit2133=== RUN TestQueueRetryMovesToBack2134=== PAUSE TestQueueRetryMovesToBack2135=== RUN TestQueueFetchRemoveLifecycle2136=== PAUSE TestQueueFetchRemoveLifecycle2137=== RUN TestQueueConcurrentWriters2138=== PAUSE TestQueueConcurrentWriters2139=== RUN TestQueueRemoveLargeClosure2140=== PAUSE TestQueueRemoveLargeClosure2141=== RUN TestServerClientIntegration2142=== PAUSE TestServerClientIntegration2143=== RUN TestServerQueueError2144=== PAUSE TestServerQueueError2145=== RUN TestGetListenerSocketActivation2146 server_test.go:210: === RUN TestGetListenerSocketActivation2147 --- PASS: TestGetListenerSocketActivation (0.00s)2148 PASS2149 2150--- PASS: TestGetListenerSocketActivation (0.01s)2151=== RUN TestDrainIsolatesPoisonPath2152=== PAUSE TestDrainIsolatesPoisonPath2153=== RUN TestRunNotBlockedByPoisonHead2154=== PAUSE TestRunNotBlockedByPoisonHead2155=== RUN TestDrainGivesUpWhenServerDown2156=== PAUSE TestDrainGivesUpWhenServerDown2157=== RUN TestFailedPathPrunedByLaterClosure2158=== PAUSE TestFailedPathPrunedByLaterClosure2159=== RUN TestWorkerUploadsAndRemoves2160=== PAUSE TestWorkerUploadsAndRemoves2161=== RUN TestWorkerSkipsGCdPaths2162=== PAUSE TestWorkerSkipsGCdPaths2163=== RUN TestWorkerPrunesClosureDeps2164=== PAUSE TestWorkerPrunesClosureDeps2165=== RUN TestDrainTimeout2166=== PAUSE TestDrainTimeout2167=== CONT TestSendPathsEmpty2168=== CONT TestServerQueueError2169--- PASS: TestSendPathsEmpty (0.00s)2170=== CONT TestQueueFetchBatchLimit2171=== CONT TestQueueRemove2172=== CONT TestQueueDeduplication2173=== CONT TestQueueEnqueueAndFetch2174=== CONT TestQueueRemoveLargeClosure2175=== CONT TestServerClientIntegration2176=== CONT TestWorkerUploadsAndRemoves2177=== CONT TestDrainTimeout2178=== CONT TestWorkerPrunesClosureDeps21792026/10/01 12:51:34 ERROR Failed to queue paths error="permission denied" count=12180--- PASS: TestServerQueueError (0.00s)2181=== CONT TestWorkerSkipsGCdPaths2182--- PASS: TestServerClientIntegration (0.00s)2183=== CONT TestDrainGivesUpWhenServerDown21842026/10/01 12:51:34 INFO Upload queue status pending=221852026/10/01 12:51:34 INFO Upload queue status pending=221862026/10/01 12:51:34 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-75714-2028051062/TestWorkerSkipsGCdPaths3713813356/002/nonexistent21872026/10/01 12:51:34 INFO Uploading batch count=121882026/10/01 12:51:34 INFO Uploading batch count=12189--- PASS: TestQueueFetchBatchLimit (0.01s)2190=== CONT TestFailedPathPrunedByLaterClosure21912026/10/01 12:51:34 INFO Uploading batch count=221922026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=221932026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/a21942026/10/01 12:51:34 INFO Uploading batch count=221952026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/b21962026/10/01 12:51:34 INFO Uploading batch count=221972026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=221982026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/c2199--- PASS: TestQueueRemove (0.01s)2200=== CONT TestQueueConcurrentWriters22012026/10/01 12:51:34 INFO Upload queue status pending=222022026/10/01 12:51:34 INFO Uploading batch count=222032026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/d2204--- PASS: TestQueueEnqueueAndFetch (0.01s)2205=== CONT TestQueueFetchRemoveLifecycle2206--- PASS: TestQueueDeduplication (0.01s)2207=== CONT TestRunNotBlockedByPoisonHead22082026/10/01 12:51:34 INFO Uploading batch count=222092026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=222102026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/e22112026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainGivesUpWhenServerDown492584457/002/f22122026/10/01 12:51:34 ERROR Drain finished with paths left in queue remaining=1022132026/10/01 12:51:34 INFO Uploading batch count=122142026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=122152026/10/01 12:51:34 INFO Uploading batch count=122162026/10/01 12:51:34 INFO Uploading batch count=122172026/10/01 12:51:34 INFO Upload queue status pending=32218--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2219=== CONT TestDrainIsolatesPoisonPath22202026/10/01 12:51:34 INFO Uploading batch count=122212026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=12222--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2223=== CONT TestQueueRetryMovesToBack2224--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)22252026/10/01 12:51:34 INFO Uploading batch count=422262026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=422272026/10/01 12:51:34 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75714-2028051062/TestDrainIsolatesPoisonPath3040058401/002/bbb2228--- PASS: TestQueueRetryMovesToBack (0.00s)22292026/10/01 12:51:34 INFO Uploading batch count=122302026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=122312026/10/01 12:51:34 INFO Uploading batch count=122322026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=122332026/10/01 12:51:34 INFO Uploading batch count=122342026/10/01 12:51:34 ERROR Upload failed error="upload failed" count=122352026/10/01 12:51:34 ERROR Drain finished with paths left in queue remaining=12236--- PASS: TestDrainIsolatesPoisonPath (0.00s)2237--- PASS: TestWorkerSkipsGCdPaths (0.03s)2238--- PASS: TestWorkerPrunesClosureDeps (0.03s)2239--- PASS: TestWorkerUploadsAndRemoves (0.03s)2240--- PASS: TestQueueRemoveLargeClosure (0.04s)2241--- PASS: TestQueueConcurrentWriters (0.14s)22422026/10/01 12:51:34 ERROR Upload failed error="context deadline exceeded" count=222432026/10/01 12:51:34 ERROR Drain finished with paths left in queue remaining=42244--- PASS: TestDrainTimeout (0.21s)22452026/10/01 12:51:35 INFO Uploading batch count=122462026/10/01 12:51:35 INFO Uploading batch count=122472026/10/01 12:51:35 INFO Uploading batch count=122482026/10/01 12:51:35 ERROR Upload failed error="upload failed" count=122492026/10/01 12:51:35 INFO Uploading batch count=122502026/10/01 12:51:35 ERROR Upload failed error="upload failed" count=122512026/10/01 12:51:35 INFO Uploading batch count=122522026/10/01 12:51:35 ERROR Upload failed error="upload failed" count=122532026/10/01 12:51:35 INFO Uploading batch count=122542026/10/01 12:51:35 ERROR Upload failed error="upload failed" count=122552026/10/01 12:51:35 ERROR Drain finished with paths left in queue remaining=12256--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2257PASS