niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #344
· 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 TestEncodeNixBase32WithRealHash97--- PASS: TestShellSplit (0.00s)98=== CONT TestPathInfoHashCompatibility99=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestGetStorePathHash102=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)103=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon104=== RUN TestGetStorePathHash/valid_store_path105=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon106=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI107=== PAUSE TestGetStorePathHash/valid_store_path108=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI109=== CONT TestDoWithRetry_BodyReplayedViaGetBody110=== RUN TestGetStorePathHash/basename_without_hyphen_should_error111=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error112=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error113=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error114=== CONT TestResolveStorePath115=== CONT TestRateLimiterFeedback116=== RUN TestRateLimiterFeedback/429_enables_limiter117=== PAUSE TestRateLimiterFeedback/429_enables_limiter118=== RUN TestRateLimiterFeedback/503_enables_limiter119=== PAUSE TestRateLimiterFeedback/503_enables_limiter120=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter121=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter122=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter124=== CONT TestPathInfoCACompatibility125=== RUN TestPathInfoCACompatibility/null_ca_field126=== PAUSE TestPathInfoCACompatibility/null_ca_field127=== RUN TestPathInfoCACompatibility/old_string_format_-_text128=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text129=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive130=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive131=== RUN TestPathInfoCACompatibility/new_structured_format_-_text132=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text133=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method134=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method135=== CONT TestParsePathInfoJSONMultiplePaths136=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths139=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths140=== CONT TestSetClientTLSErrors141=== CONT TestConvertHashToNix32142=== RUN TestConvertHashToNix32/SRI_format_to_Nix32143=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32144=== RUN TestConvertHashToNix32/already_Nix32_format145=== PAUSE TestConvertHashToNix32/already_Nix32_format146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== CONT TestScriptTokenScriptFails149=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512150=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512151=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess152=== CONT TestScriptTokenBadJSON153=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error154=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error155=== CONT TestParsePathInfoJSON156=== RUN TestParsePathInfoJSON/Nix_format157=== CONT TestScriptTokenEmptyToken1582026/10/01 10:45:46 WARN Rate limiter enabled after throttle name=server-test rate=5159=== PAUSE TestParsePathInfoJSON/Nix_format160=== RUN TestParsePathInfoJSON/Lix_format161=== PAUSE TestParsePathInfoJSON/Lix_format162=== RUN TestParsePathInfoJSON/empty_input163=== PAUSE TestParsePathInfoJSON/empty_input164=== RUN TestConvertHashToNix32/invalid_format165=== RUN TestParsePathInfoJSON/whitespace_only166=== PAUSE TestParsePathInfoJSON/whitespace_only167=== RUN TestParsePathInfoJSON/invalid_JSON168=== PAUSE TestConvertHashToNix32/invalid_format169=== CONT TestScriptTokenCachesUntilRefresh170--- PASS: TestResolveStorePath (0.00s)171=== CONT TestScriptTokenNoExpiryRerunsEveryCall172=== PAUSE TestParsePathInfoJSON/invalid_JSON173=== CONT TestFileTokenEmpty1742026/10/01 10:45:46 WARN Rate limiter enabled after throttle name=server-test rate=51752026/10/01 10:45:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:64868176--- PASS: TestFileTokenEmpty (0.00s)177=== CONT TestFileTokenMissing178=== RUN TestSetClientTLSErrors/missing_cert_file179=== PAUSE TestSetClientTLSErrors/missing_cert_file180=== RUN TestSetClientTLSErrors/missing_key_file181=== PAUSE TestSetClientTLSErrors/missing_key_file182=== RUN TestSetClientTLSErrors/missing_ca_file183=== PAUSE TestSetClientTLSErrors/missing_ca_file184=== RUN TestSetClientTLSErrors/invalid_ca_file185=== PAUSE TestSetClientTLSErrors/invalid_ca_file186=== CONT TestFileTokenReadsAndCaches187--- PASS: TestFileTokenMissing (0.00s)188=== CONT TestStaticToken189--- PASS: TestStaticToken (0.00s)190=== CONT TestDumpPathWriterError1912026/10/01 10:45:46 WARN Rate limiter backed off name=server-test rate=51922026/10/01 10:45:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:64868193--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)194--- PASS: TestScriptTokenScriptFails (0.01s)195=== CONT TestFilterOversizedClosures196=== RUN TestFilterOversizedClosures/no_limit_keeps_everything197=== CONT TestEncodeNixBase32198--- PASS: TestDoServerRequestAttachesToken (0.01s)199=== CONT TestPartSizeForNAR200=== RUN TestEncodeNixBase32/test_string_hash201=== RUN TestPartSizeForNAR/zero_stays_at_minimum202=== PAUSE TestEncodeNixBase32/test_string_hash203=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum204=== RUN TestEncodeNixBase32/empty_input205=== RUN TestPartSizeForNAR/small_stays_at_minimum206--- PASS: TestFileTokenReadsAndCaches (0.00s)207=== PAUSE TestEncodeNixBase32/empty_input208=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything209=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== CONT TestUploadMultipart_PartsInParallel211=== PAUSE TestPartSizeForNAR/small_stays_at_minimum212=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum213=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum214=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts215=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts216=== RUN TestPartSizeForNAR/1_TiB217=== PAUSE TestPartSizeForNAR/1_TiB218=== RUN TestPartSizeForNAR/5_TiB_S3_max_object219=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object220=== RUN TestPartSizeForNAR/capped_at_5_GiB221=== PAUSE TestPartSizeForNAR/capped_at_5_GiB222=== CONT TestUploadMultipart_SupersededByPeer223=== RUN TestUploadMultipart_SupersededByPeer/exists224=== PAUSE TestUploadMultipart_SupersededByPeer/exists225=== RUN TestUploadMultipart_SupersededByPeer/missing226=== PAUSE TestUploadMultipart_SupersededByPeer/missing227=== CONT TestStreamPushRequestLine228=== CONT TestCaseHackSuffix229=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== RUN TestFilterOversizedClosures/all_closures_skipped231=== PAUSE TestFilterOversizedClosures/all_closures_skipped232=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2332026/10/01 10:45:46 ERROR Upload failed error=boom count=1234--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)235=== CONT TestDumpPathSingleFile236--- PASS: TestScriptTokenBadJSON (0.01s)237=== CONT TestSetClientTLS238--- PASS: TestScriptTokenEmptyToken (0.01s)239=== CONT TestClientSignaturesByStorePath240--- PASS: TestClientSignaturesByStorePath (0.00s)241=== CONT TestDumpPathMatchesNix242=== RUN TestSetClientTLS/rejects_connection_without_client_cert243=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert244=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA245=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA246=== RUN TestSetClientTLS/preserves_debug_logging_transport247=== PAUSE TestSetClientTLS/preserves_debug_logging_transport248=== CONT TestStreamPushReportsSignatures2492026/10/01 10:45:46 ERROR Upload failed error=boom count=1250--- PASS: TestStreamPushReportsSignatures (0.00s)251=== CONT TestStreamPushBatchesUnderLoad252--- PASS: TestStreamPushRequestLine (0.01s)253=== CONT TestStreamPushGivesUpOnDeadServer2542026/10/01 10:45:46 ERROR Upload failed error="connection refused" count=202552026/10/01 10:45:46 ERROR Server seems unavailable, giving up on batch untried=17256--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)257=== CONT TestRegisterUploadedObjectReusesConnections258--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)259=== CONT TestStreamPushIsolatesFailures2602026/10/01 10:45:46 ERROR Upload failed error="bad path" count=3261--- PASS: TestStreamPushIsolatesFailures (0.00s)262=== CONT TestStreamPushReportsEveryPath263--- PASS: TestStreamPushReportsEveryPath (0.00s)264=== CONT TestShellSplitErrors265--- PASS: TestShellSplitErrors (0.00s)266=== CONT TestRateLimiterFeedback/429_enables_limiter267--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)268=== CONT TestPathInfoCACompatibility/null_ca_field269=== CONT TestRateLimiterFeedback/503_enables_limiter2702026/10/01 10:45:46 WARN Rate limiter enabled after throttle name=server-test rate=52712026/10/01 10:45:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:649442722026/10/01 10:45:46 WARN Rate limiter enabled after throttle name=server-test rate=52732026/10/01 10:45:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:649462742026/10/01 10:45:46 WARN Rate limiter backed off name=server-test rate=5275=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths276=== CONT TestPathInfoCACompatibility/old_string_format_-_text277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestPathInfoCACompatibility/new_structured_format_-_text279=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive280--- PASS: TestPathInfoCACompatibility (0.00s)281 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)282 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)283 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)284 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)285 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2872026/10/01 10:45:46 WARN Rate limiter backed off name=server-test rate=5288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)290 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)291 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)292=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)293=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295--- PASS: TestRateLimiterFeedback (0.00s)296 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)298 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)300=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI301=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512302--- PASS: TestPathInfoHashCompatibility (0.00s)303 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)304 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)305 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)307=== CONT TestGetStorePathHash/valid_store_path308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error309=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error310=== CONT TestConvertHashToNix32/invalid_format311=== CONT TestConvertHashToNix32/already_Nix32_format312=== CONT TestParsePathInfoJSON/Nix_format313=== CONT TestParsePathInfoJSON/invalid_JSON314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestParsePathInfoJSON/empty_input316=== CONT TestParsePathInfoJSON/Lix_format317--- PASS: TestDumpPathWriterError (0.04s)318=== CONT TestGetStorePathHash/basename_without_hyphen_should_error319=== CONT TestConvertHashToNix32/SRI_format_to_Nix32320=== CONT TestSetClientTLSErrors/missing_cert_file321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLSErrors/missing_key_file323=== CONT TestEncodeNixBase32/test_string_hash324=== CONT TestEncodeNixBase32/empty_input325=== CONT TestPartSizeForNAR/zero_stays_at_minimum326=== CONT TestPartSizeForNAR/1_TiB327=== CONT TestUploadMultipart_SupersededByPeer/exists328=== CONT TestPartSizeForNAR/capped_at_5_GiB329=== CONT TestPartSizeForNAR/5_TiB_S3_max_object330=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts331=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum332=== CONT TestPartSizeForNAR/small_stays_at_minimum333=== CONT TestUploadMultipart_SupersededByPeer/missing334--- PASS: TestGetStorePathHash (0.00s)335 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)336 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)337 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)338 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)339--- PASS: TestParsePathInfoJSON (0.00s)340 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)341 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)342 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)343 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)344 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)345--- PASS: TestConvertHashToNix32 (0.00s)346 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)347 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349=== CONT TestSetClientTLSErrors/missing_ca_file350--- PASS: TestEncodeNixBase32 (0.00s)351 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)352 --- PASS: TestEncodeNixBase32/empty_input (0.00s)353--- PASS: TestPartSizeForNAR (0.00s)354 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)356 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)359 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)361=== CONT TestFilterOversizedClosures/no_limit_keeps_everything362=== CONT TestFilterOversizedClosures/all_closures_skipped3632026/10/01 10:45:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50364=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3652026/10/01 10:45:46 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=2000366--- PASS: TestFilterOversizedClosures (0.00s)367 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)368 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)369 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)370=== CONT TestSetClientTLS/rejects_connection_without_client_cert371--- PASS: TestSetClientTLSErrors (0.01s)372 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)374 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)375 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)376=== CONT TestSetClientTLS/preserves_debug_logging_transport377--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)378 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)380=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA381--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)3822026/10/01 10:45:46 http: TLS handshake error from 127.0.0.1:64955: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-69215-2353416696/postgres1403889993/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-69215-2353416696/postgres1403889993/data -l logfile start421422/nix/var/nix/builds/nix-69215-2353416696/postgres1403889993:5432 - no response4232026-10-01 10:45:48.513 UTC [69289] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 10:45:48.513 UTC [69289] LOG: listening on Unix socket "/nix/var/nix/builds/nix-69215-2353416696/postgres1403889993/.s.PGSQL.5432"4252026-10-01 10:45:48.515 UTC [69296] LOG: database system was shut down at 2026-10-01 10:45:48 UTC4262026-10-01 10:45:48.516 UTC [69289] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-69215-2353416696/postgres1403889993:5432 - accepting connections428{"timestamp":"2026-10-01T10:45:48.726346Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"44290bde-b50c-437c-b50a-6841958bb2a1","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}429{"timestamp":"2026-10-01T10:45:48.82805Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d28fb13a-202c-49c3-8337-bb0c070f30a6","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(7)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestConnectWaitsForAPeerMigration471=== PAUSE TestConnectWaitsForAPeerMigration472=== RUN TestLeadElectsOneAndHandsOver473=== PAUSE TestLeadElectsOneAndHandsOver474=== RUN TestLeadIncumbentWinsAfterRestart4752026/10/01 10:45:49 INFO lead: acquired remote=192.0.2.1:12344762026/10/01 10:45:49 INFO lead: released remote=192.0.2.1:12344772026/10/01 10:45:49 INFO lead: acquired remote=192.0.2.1:12344782026/10/01 10:45:49 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (0.86s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestGCAdvisoryLockBlocksConcurrentRun483=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun484=== RUN TestGCBugBareHashReferences485=== PAUSE TestGCBugBareHashReferences486=== RUN TestGCMetrics487=== PAUSE TestGCMetrics488=== RUN TestPushDedupSurvivesConcurrentGC489=== PAUSE TestPushDedupSurvivesConcurrentGC490=== RUN TestDeduplicatedObjectsRecordedAsPending491=== PAUSE TestDeduplicatedObjectsRecordedAsPending492=== RUN TestGCSweepSkipsPendingObjects493=== PAUSE TestGCSweepSkipsPendingObjects494=== RUN TestTombstonedObjectOfferedWithoutWaiting495=== PAUSE TestTombstonedObjectOfferedWithoutWaiting496=== RUN TestGCSweepDeliversEachKeyOnce497=== PAUSE TestGCSweepDeliversEachKeyOnce498=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection499=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection500=== RUN TestForceGCDuringPushOffersSweptObject501=== PAUSE TestForceGCDuringPushOffersSweptObject502=== RUN TestFailedS3DeleteKeepsTombstone503=== PAUSE TestFailedS3DeleteKeepsTombstone504=== RUN TestSweepSkipsRowsLockedByPush505=== PAUSE TestSweepSkipsRowsLockedByPush506=== RUN TestRegisterCompletedObjectNeedsPendingRow507=== PAUSE TestRegisterCompletedObjectNeedsPendingRow508=== RUN TestGetExistingObjectsLocksRows509=== PAUSE TestGetExistingObjectsLocksRows510=== RUN TestSweepRechecksPendingAfterLocking511=== PAUSE TestSweepRechecksPendingAfterLocking512=== RUN TestPushWaitsForSweepHoldingRow513=== PAUSE TestPushWaitsForSweepHoldingRow514=== RUN TestCommitRacingPendingCleanupKeepsObjects515=== PAUSE TestCommitRacingPendingCleanupKeepsObjects516=== RUN TestGCEndsOnShutdown517=== PAUSE TestGCEndsOnShutdown518=== RUN TestGCTaskStore_StartNew519=== PAUSE TestGCTaskStore_StartNew520=== RUN TestGCTaskStore_DeduplicateSameParams521=== PAUSE TestGCTaskStore_DeduplicateSameParams522=== RUN TestGCTaskStore_ConflictDifferentParams523=== PAUSE TestGCTaskStore_ConflictDifferentParams524=== RUN TestGCTaskStore_GetEmpty525=== PAUSE TestGCTaskStore_GetEmpty526=== RUN TestGCTaskStore_GetReturnsLatest527=== PAUSE TestGCTaskStore_GetReturnsLatest528=== RUN TestGCTaskStore_CompletedAllowsNewTask529=== PAUSE TestGCTaskStore_CompletedAllowsNewTask530=== RUN TestGCTaskStore_PhaseUpdates531=== PAUSE TestGCTaskStore_PhaseUpdates532=== RUN TestGCTaskStore_Fail533=== PAUSE TestGCTaskStore_Fail534=== RUN TestGracefulShutdownDrainsInflight535=== PAUSE TestGracefulShutdownDrainsInflight536=== RUN TestService_healthCheckHandler537=== PAUSE TestService_healthCheckHandler538=== RUN TestService_readinessHandler539=== PAUSE TestService_readinessHandler540=== RUN TestGenerateLandingPage541=== PAUSE TestGenerateLandingPage542=== RUN TestCacheConfigHandlerMaxNarSize543=== PAUSE TestCacheConfigHandlerMaxNarSize544=== RUN TestCreatePendingClosureRejectsOversizedNAR545=== PAUSE TestCreatePendingClosureRejectsOversizedNAR546=== RUN TestNARDeduplicationMetadataUploadBug547=== PAUSE TestNARDeduplicationMetadataUploadBug548=== RUN TestMetricsInventory549=== PAUSE TestMetricsInventory550=== RUN TestService_NativeMTLS551=== PAUSE TestService_NativeMTLS552=== RUN TestServerTLSConfig553=== PAUSE TestServerTLSConfig554=== RUN TestMultipartCleanup555=== PAUSE TestMultipartCleanup556=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded557=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded558=== RUN TestPendingCleanupUsesOneCutoff559=== PAUSE TestPendingCleanupUsesOneCutoff560=== RUN TestObjectStatsTrigger561=== PAUSE TestObjectStatsTrigger562=== RUN TestOrphanedObjectsGC563=== PAUSE TestOrphanedObjectsGC564=== RUN TestOrphanedObjectsGCStressTest565=== PAUSE TestOrphanedObjectsGCStressTest566=== RUN TestCreatePin_ReservedPins567=== PAUSE TestCreatePin_ReservedPins568=== RUN TestPresentReportsOnlyClosureRoots569=== PAUSE TestPresentReportsOnlyClosureRoots570=== RUN TestPresentNotReportedWhileGCDeletesClosure571=== PAUSE TestPresentNotReportedWhileGCDeletesClosure572=== RUN TestParseSingleRange573=== PAUSE TestParseSingleRange574=== RUN TestProxyHeadersOnlyTrustedOnSocket575=== PAUSE TestProxyHeadersOnlyTrustedOnSocket576=== RUN TestIsValidCachePath577=== PAUSE TestIsValidCachePath578=== RUN TestReadProxyNarinfo579=== PAUSE TestReadProxyNarinfo580=== RUN TestReadProxyNarinfoAlreadyDecompressed581=== PAUSE TestReadProxyNarinfoAlreadyDecompressed582=== RUN TestReadProxyNarStreaming583=== PAUSE TestReadProxyNarStreaming584=== RUN TestReadProxy404585=== PAUSE TestReadProxy404586=== RUN TestReadProxyInvalidPath587=== PAUSE TestReadProxyInvalidPath588=== RUN TestReadProxyHead589=== PAUSE TestReadProxyHead590=== RUN TestReadProxyOutlastsServerWriteTimeout591=== PAUSE TestReadProxyOutlastsServerWriteTimeout592=== RUN TestReadProxyConditionalGet593=== PAUSE TestReadProxyConditionalGet594=== RUN TestReadProxyRootRedirectsToIndexHTML595=== PAUSE TestReadProxyRootRedirectsToIndexHTML596=== RUN TestReadProxyDisabled597=== PAUSE TestReadProxyDisabled598=== RUN TestReadRedirectNar599=== PAUSE TestReadRedirectNar600=== RUN TestReadRedirectKeepsNarinfoProxied601=== PAUSE TestReadRedirectKeepsNarinfoProxied602=== RUN TestReadProxyRangeRequest603=== PAUSE TestReadProxyRangeRequest604=== RUN TestReadRedirectUsesPublicS3URL605=== PAUSE TestReadRedirectUsesPublicS3URL606=== RUN TestPush_OverlappingRootsStoreOneRowPerKey607=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey608=== RUN TestPush_CompleteCommitsEveryRoot609=== PAUSE TestPush_CompleteCommitsEveryRoot610=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit611=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit612=== RUN TestPush_RejectsBadRequests613=== PAUSE TestPush_RejectsBadRequests614=== RUN TestPush_SignsNarinfosOfItsPendingObjects615=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects616=== RUN TestRedundantMultipartUpload617=== PAUSE TestRedundantMultipartUpload618=== RUN TestCompleteMultipartUpload_ErrorButObjectExists619=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists620=== RUN TestCompletedNarNotReofferedAcrossClosures621=== PAUSE TestCompletedNarNotReofferedAcrossClosures622=== RUN TestPresignedUploadRegisteredBeforeCommit623=== PAUSE TestPresignedUploadRegisteredBeforeCommit624=== RUN TestService_Rustfstest625=== PAUSE TestService_Rustfstest626=== RUN TestParseSize627=== PAUSE TestParseSize628=== RUN TestSkippedUploadsHandler629=== PAUSE TestSkippedUploadsHandler630=== RUN TestSystemdListenerNotActivated631--- PASS: TestSystemdListenerNotActivated (0.00s)632=== RUN TestWatchdogBeatsWhenHealthy633--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)634=== RUN TestWatchdogSkipsWhenUnhealthy6352026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 10:45:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 10:45:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 10:45:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"645--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)646=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle647=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle648=== RUN TestProxyWriteTimeout649=== PAUSE TestProxyWriteTimeout650=== RUN TestPendingClosureWriteTimeout651=== PAUSE TestPendingClosureWriteTimeout652=== RUN TestIsValidUploadKey653=== PAUSE TestIsValidUploadKey654=== RUN TestUploadHandlersRejectInvalidKeys655=== PAUSE TestUploadHandlersRejectInvalidKeys656=== RUN TestUploadHandlersRejectOversizedBody657=== PAUSE TestUploadHandlersRejectOversizedBody658=== RUN TestService_cleanupPendingClosuresHandler659=== PAUSE TestService_cleanupPendingClosuresHandler660=== RUN TestService_createPendingClosureHandler661=== PAUSE TestService_createPendingClosureHandler662=== RUN TestService_verifyS3Integrity663=== PAUSE TestService_verifyS3Integrity664=== RUN TestCompleteMultipartUnregistered665=== PAUSE TestCompleteMultipartUnregistered666=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT667=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT668=== CONT TestPresignedUploadRegisteredBeforeCommit669=== CONT TestPush_CompleteCommitsEveryRoot670=== CONT TestUploadHandlersRejectInvalidKeys671=== CONT TestReadRedirectKeepsNarinfoProxied672=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info673=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info674=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal675=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal676=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key677=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key678=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key679=== CONT TestService_AuthMiddleware680=== CONT TestService_createPendingClosureHandler681=== CONT TestRedundantMultipartUpload682=== CONT TestPush_OverlappingRootsStoreOneRowPerKey683=== CONT TestReadRedirectUsesPublicS3URL684=== CONT TestReadProxyRangeRequest685=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key686=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT6872026/10/01 10:45:50 INFO Received push request method=POST path=/api/pushes6882026/10/01 10:45:50 INFO Received complete push request method=POST path=/api/pushes/1/complete689--- PASS: TestPush_CompleteCommitsEveryRoot (0.50s)690=== CONT TestCompleteMultipartUnregistered6912026/10/01 10:45:50 INFO Received uploads request method=POST path=/api/pending_closures6922026/10/01 10:45:50 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst6932026/10/01 10:45:50 INFO Received uploads request method=POST path=/api/pending_closures694--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.62s)695=== CONT TestService_verifyS3Integrity6962026/10/01 10:45:50 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"697--- PASS: TestService_AuthMiddleware (0.75s)698=== CONT TestGCTaskStore_StartNew699--- PASS: TestGCTaskStore_StartNew (0.00s)700=== CONT TestReadRedirectNar7012026/10/01 10:45:50 INFO Received push request method=POST path=/api/pushes702--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.99s)703=== CONT TestReadProxyDisabled7042026/10/01 10:45:51 INFO Received uploads request method=POST path=/api/pending_closures7052026/10/01 10:45:51 INFO Received uploads request method=POST path=/api/pending_closures7062026/10/01 10:45:51 INFO Received uploads request method=POST path=/api/pending_closures7072026/10/01 10:45:51 INFO Received uploads request method=POST path=/api/pending_closures7082026/10/01 10:45:51 INFO Received uploads request method=POST path=/api/pending_closures709--- PASS: TestReadProxyRangeRequest (1.58s)710=== CONT TestReadProxyRootRedirectsToIndexHTML711--- PASS: TestReadRedirectUsesPublicS3URL (1.81s)712=== CONT TestReadProxyConditionalGet713--- PASS: TestReadRedirectKeepsNarinfoProxied (2.05s)714=== CONT TestReadProxyOutlastsServerWriteTimeout7152026/10/01 10:45:52 INFO Received uploads request method=POST path=/api/pending_closures716--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.39s)717=== CONT TestReadProxyHead7182026/10/01 10:45:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7192026/10/01 10:45:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst720--- PASS: TestCompleteMultipartUnregistered (2.00s)721=== CONT TestReadProxyInvalidPath7222026/10/01 10:45:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7232026/10/01 10:45:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7242026/10/01 10:45:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLjhlOWY5OGY3LWUzZTQtNGZkOS04NDUyLTZlY2EzNTYwZTk4M3gxNzkwODUxNTUxMzE0NTE2MDAw parts=107252026/10/01 10:45:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7262026/10/01 10:45:52 INFO Completed upload id=17272026/10/01 10:45:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007282026/10/01 10:45:52 INFO Received uploads request method=POST path=/api/pending_closures7292026/10/01 10:45:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures7302026/10/01 10:45:52 INFO Aborted multipart uploads count=0 kept=07312026/10/01 10:45:52 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=07322026/10/01 10:45:52 INFO Vacuumed table table=pending_closures7332026/10/01 10:45:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLjQ2YzE5YzRkLTlmN2UtNDM2Ny1iOWMwLWY4ODc0Yzg4Yjk4YngxNzkwODUxNTUxMTE3Nzg4MDAw parts=127342026/10/01 10:45:52 INFO Received uploads request method=POST path=/api/pending_closures7352026/10/01 10:45:52 INFO Vacuumed table table=pending_objects7362026/10/01 10:45:52 INFO Vacuumed table table=multipart_uploads7372026/10/01 10:45:52 INFO Received uploads request method=POST path=/api/pending_closures7382026/10/01 10:45:52 INFO Vacuumed table table=closures7392026/10/01 10:45:52 INFO Vacuumed table table=objects7402026/10/01 10:45:52 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000741--- PASS: TestService_createPendingClosureHandler (2.77s)742=== CONT TestReadProxy4047432026/10/01 10:45:52 INFO Received uploads request method=POST path=/api/pending_closures744--- PASS: TestReadRedirectNar (2.27s)745=== CONT TestReadProxyNarStreaming746--- PASS: TestReadProxyDisabled (2.24s)747=== CONT TestReadProxyNarinfoAlreadyDecompressed748--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.19s)749=== CONT TestReadProxyNarinfo7502026/10/01 10:45:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7512026/10/01 10:45:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLjg4OTg2MDM5LWU1NGItNGZkZC1hMjU2LTc2ZjRkYzA1OTE2OHgxNzkwODUxNTUyODMyOTgwMDAw parts=107522026/10/01 10:45:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete753--- PASS: TestReadProxyConditionalGet (2.29s)754=== CONT TestIsValidCachePath755=== RUN TestIsValidCachePath/narinfo756=== PAUSE TestIsValidCachePath/narinfo757=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars758=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars759=== RUN TestIsValidCachePath/nar_zst760=== PAUSE TestIsValidCachePath/nar_zst761=== RUN TestIsValidCachePath/nar_xz762=== PAUSE TestIsValidCachePath/nar_xz763=== RUN TestIsValidCachePath/nar_bz2764=== PAUSE TestIsValidCachePath/nar_bz2765=== RUN TestIsValidCachePath/nar_uncompressed766=== PAUSE TestIsValidCachePath/nar_uncompressed767=== RUN TestIsValidCachePath/ls768=== PAUSE TestIsValidCachePath/ls769=== RUN TestIsValidCachePath/log770=== PAUSE TestIsValidCachePath/log771=== RUN TestIsValidCachePath/realisation772=== PAUSE TestIsValidCachePath/realisation773=== RUN TestIsValidCachePath/nix-cache-info774=== PAUSE TestIsValidCachePath/nix-cache-info775=== RUN TestIsValidCachePath/index.html776=== PAUSE TestIsValidCachePath/index.html777=== RUN TestIsValidCachePath/traversal_parent778=== PAUSE TestIsValidCachePath/traversal_parent779=== RUN TestIsValidCachePath/traversal_in_middle780=== PAUSE TestIsValidCachePath/traversal_in_middle781=== RUN TestIsValidCachePath/invalid_char_e782=== PAUSE TestIsValidCachePath/invalid_char_e783=== RUN TestIsValidCachePath/invalid_char_u784=== PAUSE TestIsValidCachePath/invalid_char_u785=== RUN TestIsValidCachePath/random_path786=== PAUSE TestIsValidCachePath/random_path787=== RUN TestIsValidCachePath/empty788=== PAUSE TestIsValidCachePath/empty789=== RUN TestIsValidCachePath/leading_slash790=== PAUSE TestIsValidCachePath/leading_slash791=== RUN TestIsValidCachePath/wrong_extension792=== PAUSE TestIsValidCachePath/wrong_extension793=== RUN TestIsValidCachePath/short_hash794=== PAUSE TestIsValidCachePath/short_hash795=== CONT TestProxyHeadersOnlyTrustedOnSocket7962026/10/01 10:45:54 INFO Completed upload id=17972026/10/01 10:45:54 INFO Received uploads request method=POST path=/api/pending_closures7982026/10/01 10:45:54 INFO Received uploads request method=POST path=/api/pending_closures7992026/10/01 10:45:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8002026/10/01 10:45:54 WARN Found objects in DB but missing from S3, will re-upload count=1801--- PASS: TestService_verifyS3Integrity (3.50s)802=== CONT TestParseSingleRange803=== RUN TestParseSingleRange/none804=== PAUSE TestParseSingleRange/none805=== RUN TestParseSingleRange/unknown_unit806=== PAUSE TestParseSingleRange/unknown_unit807=== RUN TestParseSingleRange/multi-range_ignored808=== PAUSE TestParseSingleRange/multi-range_ignored809=== RUN TestParseSingleRange/malformed_no_dash810=== PAUSE TestParseSingleRange/malformed_no_dash811=== RUN TestParseSingleRange/malformed_both_empty812=== PAUSE TestParseSingleRange/malformed_both_empty813=== RUN TestParseSingleRange/malformed_end_before_start814=== PAUSE TestParseSingleRange/malformed_end_before_start815=== RUN TestParseSingleRange/closed816=== PAUSE TestParseSingleRange/closed817=== RUN TestParseSingleRange/open-ended818=== PAUSE TestParseSingleRange/open-ended819=== RUN TestParseSingleRange/end_clamped_to_size820=== PAUSE TestParseSingleRange/end_clamped_to_size821=== RUN TestParseSingleRange/suffix822=== PAUSE TestParseSingleRange/suffix823=== RUN TestParseSingleRange/suffix_exceeds_size824=== PAUSE TestParseSingleRange/suffix_exceeds_size825=== RUN TestParseSingleRange/single_byte826=== PAUSE TestParseSingleRange/single_byte827=== RUN TestParseSingleRange/start_past_EOF828=== PAUSE TestParseSingleRange/start_past_EOF829=== RUN TestParseSingleRange/start_far_past_EOF830=== PAUSE TestParseSingleRange/start_far_past_EOF831=== CONT TestPresentNotReportedWhileGCDeletesClosure8322026/10/01 10:45:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8332026/10/01 10:45:54 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLmIzOWU0ZTNiLWE2NmMtNDc4ZS1hYzE4LTJhZjI1Y2RjYjYzOXgxNzkwODUxNTUyNzI2MDY4MDAw error="Get \"http://127.0.0.1:1/bucket6/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"8342026/10/01 10:45:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLjk1MzI2NmQ0LWFiZjItNDQ5Mi1hMWJlLTk4YzFhNTdiMGQwY3gxNzkwODUxNTUyNjc4MDczMDAw parts=128352026/10/01 10:45:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8362026/10/01 10:45:54 INFO Aborted multipart uploads count=1 kept=0837--- PASS: TestRedundantMultipartUpload (4.25s)838=== CONT TestPresentReportsOnlyClosureRoots839--- PASS: TestReadProxyHead (2.30s)840=== CONT TestCreatePin_ReservedPins8412026/10/01 10:45:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65064/oidc842--- PASS: TestReadProxyInvalidPath (2.30s)843=== CONT TestOrphanedObjectsGCStressTest844--- PASS: TestReadProxy404 (2.29s)845=== CONT TestOrphanedObjectsGC846--- PASS: TestReadProxyNarStreaming (2.22s)847=== CONT TestObjectStatsTrigger848--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.19s)849=== CONT TestPendingCleanupUsesOneCutoff8502026/10/01 10:45:55 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"8512026/10/01 10:45:55 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216852--- PASS: TestReadProxyNarinfo (2.20s)853=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8542026/10/01 10:45:56 INFO Starting HTTP server address=/nix/var/nix/builds/nix-69215-2353416696/TestProxyHeadersOnlyTrustedOnSocket3315420929/001/proxy.sock8552026/10/01 10:45:56 INFO Starting HTTP server address=127.0.0.1:650918562026/10/01 10:45:56 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8572026/10/01 10:45:56 INFO Shutdown signal received, draining in-flight requests timeout=10s858--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.07s)859=== CONT TestMultipartCleanup860--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.28s)861=== CONT TestServerTLSConfig862=== RUN TestServerTLSConfig/no_client_CA863=== PAUSE TestServerTLSConfig/no_client_CA864=== RUN TestServerTLSConfig/missing_CA_file865=== PAUSE TestServerTLSConfig/missing_CA_file866=== RUN TestServerTLSConfig/not_a_PEM_file867=== PAUSE TestServerTLSConfig/not_a_PEM_file868=== CONT TestService_NativeMTLS869--- PASS: TestPresentReportsOnlyClosureRoots (2.17s)870=== CONT TestMetricsInventory8712026/10/01 10:45:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux8722026/10/01 10:45:57 WARN Refused reserved pin name=worker-x86_64-linux8732026/10/01 10:45:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux8742026/10/01 10:45:57 INFO Received create pin request method=POST path=/api/pins/my-app8752026/10/01 10:45:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux876--- PASS: TestCreatePin_ReservedPins (2.43s)877=== CONT TestNARDeduplicationMetadataUploadBug878--- PASS: TestObjectStatsTrigger (2.54s)879=== CONT TestCreatePendingClosureRejectsOversizedNAR8802026/10/01 10:45:57 INFO Received uploads request method=POST path=/api/pending_closures881--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)882=== CONT TestCacheConfigHandlerMaxNarSize883--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)884=== CONT TestGenerateLandingPage885--- PASS: TestGenerateLandingPage (0.01s)886=== CONT TestService_readinessHandler8872026/10/01 10:45:58 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/01 10:45:58 INFO Received uploads request method=POST path=/api/pending_closures889=== NAME TestOrphanedObjectsGC890 orphaned_objects_gc_test.go:290: GC Test Summary:891 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A892 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B893 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)894 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)895 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects896--- PASS: TestOrphanedObjectsGC (3.11s)897=== CONT TestService_healthCheckHandler8982026/10/01 10:45:58 INFO Received cleanup request method=DELETE path=/api/pending_closures899--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.57s)900=== CONT TestGracefulShutdownDrainsInflight9012026/10/01 10:45:58 INFO Starting HTTP server address=127.0.0.1:651129022026/10/01 10:45:58 INFO Shutdown signal received, draining in-flight requests timeout=10s903--- PASS: TestGracefulShutdownDrainsInflight (0.07s)904=== CONT TestGCTaskStore_Fail905--- PASS: TestGCTaskStore_Fail (0.00s)906=== CONT TestGCTaskStore_PhaseUpdates907--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)908=== CONT TestGCTaskStore_CompletedAllowsNewTask909--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)910=== CONT TestGCTaskStore_GetReturnsLatest911--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)912=== CONT TestGCTaskStore_GetEmpty913--- PASS: TestGCTaskStore_GetEmpty (0.00s)914=== CONT TestGCTaskStore_ConflictDifferentParams915--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)916=== CONT TestGCTaskStore_DeduplicateSameParams917--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)918=== CONT TestPush_SignsNarinfosOfItsPendingObjects9192026/10/01 10:45:58 INFO Received uploads request method=POST path=/api/pending_closures920--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.79s)921=== CONT TestUploadHandlersRejectOversizedBody922=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure923=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure924=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart925=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart926=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts927=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts928=== CONT TestService_cleanupPendingClosuresHandler9292026/10/01 10:45:59 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/01 10:45:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9312026/10/01 10:45:59 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket34/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9322026/10/01 10:45:59 INFO Aborted multipart uploads count=0 kept=19332026/10/01 10:45:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9342026/10/01 10:45:59 INFO Aborted multipart uploads count=1 kept=0935--- PASS: TestMultipartCleanup (3.05s)936=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9372026/10/01 10:45:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9382026/10/01 10:45:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"939--- PASS: TestService_NativeMTLS (2.89s)940=== CONT TestLeadElectsOneAndHandsOver941--- PASS: TestMetricsInventory (3.18s)942=== CONT TestGCEndsOnShutdown943=== NAME TestNARDeduplicationMetadataUploadBug944 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-69215-2353416696/TestNARDeduplicationMetadataUploadBug517033765/001/store/6izsyghjwb7v751nyl28nayj1xscy6ya-file1.txt9452026/10/01 10:46:00 INFO Received push request method=POST path=/api/pushes9462026/10/01 10:46:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9472026/10/01 10:46:00 INFO Uploading 6izsyghjwb7v751nyl28nayj1xscy6ya-file1.txt (160B)9482026/10/01 10:46:00 WARN readiness check failed error="closed pool"949--- PASS: TestService_readinessHandler (2.62s)950=== CONT TestCommitRacingPendingCleanupKeepsObjects9512026/10/01 10:46:00 WARN Failed to register uploaded object key=6izsyghjwb7v751nyl28nayj1xscy6ya.ls error="server returned 404: 404 page not found\n"9522026/10/01 10:46:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9532026/10/01 10:46:00 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9542026/10/01 10:46:00 INFO Signed narinfos id=1 count=19552026/10/01 10:46:00 INFO Uploading 1 narinfos9562026/10/01 10:46:00 INFO Received complete push request method=POST path=/api/pushes/1/complete9572026/10/01 10:46:00 WARN Failed to register uploaded object key=6izsyghjwb7v751nyl28nayj1xscy6ya.narinfo error="server returned 404: 404 page not found\n"9582026/10/01 10:46:00 INFO Upload complete. (132ms)959=== NAME TestNARDeduplicationMetadataUploadBug960 metadata_upload_test.go:54: Retrieved narinfo from S3:961 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestNARDeduplicationMetadataUploadBug517033765/001/store/6izsyghjwb7v751nyl28nayj1xscy6ya-file1.txt962 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst963 Compression: zstd964 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf965 NarSize: 160966 References: 967 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf968 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)969 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):970 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}971 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-69215-2353416696/TestNARDeduplicationMetadataUploadBug517033765/001/store/8nv9xqh0ss3p582x77l7r0vrxqfjyphf-file2.txt9722026/10/01 10:46:00 INFO Received push request method=POST path=/api/pushes9732026/10/01 10:46:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9742026/10/01 10:46:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9752026/10/01 10:46:00 INFO Signed narinfos id=2 count=19762026/10/01 10:46:00 INFO Uploading 1 narinfos9772026/10/01 10:46:00 WARN Failed to register uploaded object key=8nv9xqh0ss3p582x77l7r0vrxqfjyphf.ls error="server returned 404: 404 page not found\n"9782026/10/01 10:46:00 INFO Received complete push request method=POST path=/api/pushes/2/complete9792026/10/01 10:46:00 WARN Failed to register uploaded object key=8nv9xqh0ss3p582x77l7r0vrxqfjyphf.narinfo error="server returned 404: 404 page not found\n"9802026/10/01 10:46:00 INFO Upload complete. (90ms)981 metadata_upload_test.go:76: Retrieved narinfo from S3:982 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestNARDeduplicationMetadataUploadBug517033765/001/store/8nv9xqh0ss3p582x77l7r0vrxqfjyphf-file2.txt983 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst984 Compression: zstd985 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf986 NarSize: 160987 References: 988 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf989 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)990 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):991 {"version":1,"root":{"type":"regular","size":44}}992--- PASS: TestNARDeduplicationMetadataUploadBug (3.61s)993=== CONT TestPushWaitsForSweepHoldingRow994--- PASS: TestService_healthCheckHandler (2.55s)995=== CONT TestSweepRechecksPendingAfterLocking9962026/10/01 10:46:01 INFO Received push request method=POST path=/api/pushes9972026/10/01 10:46:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9982026/10/01 10:46:01 INFO Signed narinfos id=1 count=1999--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.43s)1000=== CONT TestGetExistingObjectsLocksRows10012026/10/01 10:46:01 INFO Received cleanup request method=DELETE path=/api/pending_closures10022026/10/01 10:46:01 INFO Aborted multipart uploads count=0 kept=010032026/10/01 10:46:01 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/01 10:46:01 INFO Received cleanup request method=DELETE path=/api/pending_closures10052026/10/01 10:46:01 INFO Aborted multipart uploads count=1 kept=010062026/10/01 10:46:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026-10-01 10:46:01.420 UTC [69480] ERROR: Closure does not exist: id=110082026-10-01 10:46:01.420 UTC [69480] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE10092026-10-01 10:46:01.420 UTC [69480] STATEMENT: -- name: CommitPendingClosure :exec1010 SELECT commit_pending_closure($1::bigint)1011 1012--- PASS: TestService_cleanupPendingClosuresHandler (2.59s)1013=== CONT TestRegisterCompletedObjectNeedsPendingRow10142026/10/01 10:46:01 INFO Received push request method=POST path=/api/pushes10152026/10/01 10:46:01 INFO Received complete push request method=POST path=/api/pushes/1/complete10162026/10/01 10:46:01 INFO Received push request method=POST path=/api/pushes10172026/10/01 10:46:01 INFO Aborted multipart uploads count=0 kept=010182026/10/01 10:46:01 WARN Force mode enabled - objects will be deleted immediately without grace period10192026/10/01 10:46:01 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=010202026/10/01 10:46:01 INFO Vacuumed table table=pending_closures10212026/10/01 10:46:01 INFO Vacuumed table table=pending_objects10222026/10/01 10:46:01 INFO Vacuumed table table=multipart_uploads10232026/10/01 10:46:01 INFO lead: acquired remote=192.0.2.1:123410242026/10/01 10:46:01 INFO Vacuumed table table=closures10252026/10/01 10:46:02 INFO Vacuumed table table=objects10262026/10/01 10:46:02 INFO Received complete push request method=POST path=/api/pushes/2/complete1027--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.80s)1028=== CONT TestSweepSkipsRowsLockedByPush10292026/10/01 10:46:02 INFO lead: released remote=192.0.2.1:123410302026/10/01 10:46:02 INFO lead: acquired remote=192.0.2.1:123410312026/10/01 10:46:02 INFO lead: released remote=192.0.2.1:12341032--- PASS: TestLeadElectsOneAndHandsOver (2.94s)1033=== CONT TestFailedS3DeleteKeepsTombstone1034--- PASS: TestGCEndsOnShutdown (2.67s)1035=== CONT TestForceGCDuringPushOffersSweptObject1036=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1037=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1038=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1039=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1040=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1041=== NAME TestOrphanedObjectsGCStressTest1042 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1043 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion10442026/10/01 10:46:02 INFO Aborted multipart uploads count=0 kept=010452026/10/01 10:46:02 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/10/01 10:46:02 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=010472026/10/01 10:46:02 INFO Vacuumed table table=pending_closures10482026/10/01 10:46:02 INFO Vacuumed table table=pending_objects10492026/10/01 10:46:02 INFO Vacuumed table table=multipart_uploads10502026/10/01 10:46:02 INFO Vacuumed table table=closures10512026/10/01 10:46:02 INFO Vacuumed table table=objects1052--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.39s)1053=== CONT TestGCSweepDeliversEachKeyOnce10542026/10/01 10:46:03 INFO Aborted multipart uploads count=0 kept=010552026/10/01 10:46:03 WARN Force mode enabled - objects will be deleted immediately without grace period10562026/10/01 10:46:03 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=010572026/10/01 10:46:03 INFO Vacuumed table table=pending_closures10582026/10/01 10:46:03 INFO Vacuumed table table=pending_objects10592026/10/01 10:46:03 INFO Vacuumed table table=multipart_uploads10602026/10/01 10:46:03 INFO Vacuumed table table=closures10612026/10/01 10:46:03 INFO Vacuumed table table=objects1062--- PASS: TestSweepRechecksPendingAfterLocking (2.33s)1063=== CONT TestTombstonedObjectOfferedWithoutWaiting10642026/10/01 10:46:03 INFO Received uploads request method=POST path=/api/pending_closures1065--- PASS: TestGetExistingObjectsLocksRows (2.26s)1066=== CONT TestGCSweepSkipsPendingObjects1067--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.19s)1068=== CONT TestDeduplicatedObjectsRecordedAsPending1069--- PASS: TestPushWaitsForSweepHoldingRow (2.91s)1070=== CONT TestPushDedupSurvivesConcurrentGC10712026/10/01 10:46:03 INFO Aborted multipart uploads count=0 kept=010722026/10/01 10:46:03 WARN Force mode enabled - objects will be deleted immediately without grace period10732026/10/01 10:46:03 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=010742026/10/01 10:46:03 INFO Vacuumed table table=pending_closures10752026/10/01 10:46:03 INFO Vacuumed table table=pending_objects10762026/10/01 10:46:03 INFO Vacuumed table table=multipart_uploads10772026/10/01 10:46:03 INFO Vacuumed table table=closures10782026/10/01 10:46:03 INFO Vacuumed table table=objects10792026/10/01 10:46:03 INFO Aborted multipart uploads count=0 kept=010802026/10/01 10:46:03 WARN Force mode enabled - objects will be deleted immediately without grace period10812026/10/01 10:46:03 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=010822026/10/01 10:46:03 INFO Vacuumed table table=pending_closures10832026/10/01 10:46:03 INFO Vacuumed table table=pending_objects10842026/10/01 10:46:03 INFO Vacuumed table table=multipart_uploads10852026/10/01 10:46:03 INFO Vacuumed table table=closures10862026/10/01 10:46:03 INFO Vacuumed table table=objects1087--- PASS: TestSweepSkipsRowsLockedByPush (1.91s)1088=== CONT TestGCMetrics10892026/10/01 10:46:04 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/01 10:46:04 INFO Aborted multipart uploads count=0 kept=010912026/10/01 10:46:04 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/01 10:46:04 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10932026/10/01 10:46:04 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1094--- PASS: TestFailedS3DeleteKeepsTombstone (1.95s)1095=== CONT TestGCBugBareHashReferences10962026/10/01 10:46:04 INFO Aborted multipart uploads count=1 kept=010972026/10/01 10:46:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10982026/10/01 10:46:04 INFO Aborted multipart uploads count=1 kept=01099--- PASS: TestPendingCleanupUsesOneCutoff (8.82s)1100=== CONT TestGCAdvisoryLockBlocksConcurrentRun11012026/10/01 10:46:04 INFO Received uploads request method=POST path=/api/pending_closures1102--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.29s)1103=== CONT TestLeadEndsOnShutdown11042026/10/01 10:46:04 INFO Aborted multipart uploads count=0 kept=011052026/10/01 10:46:04 WARN Force mode enabled - objects will be deleted immediately without grace period11062026/10/01 10:46:05 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=011072026/10/01 10:46:05 INFO Vacuumed table table=pending_closures11082026/10/01 10:46:05 INFO Vacuumed table table=pending_objects11092026/10/01 10:46:05 INFO Vacuumed table table=multipart_uploads11102026/10/01 10:46:05 INFO Vacuumed table table=closures11112026/10/01 10:46:05 INFO Vacuumed table table=objects1112--- PASS: TestGCSweepDeliversEachKeyOnce (2.34s)1113=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11142026/10/01 10:46:05 INFO Received uploads request method=POST path=/api/pending_closures1115=== NAME TestOrphanedObjectsGCStressTest1116 orphaned_objects_gc_test.go:509: Stress test completed successfully:1117 orphaned_objects_gc_test.go:510: - Active objects preserved: 201118 orphaned_objects_gc_test.go:511: - Objects deleted: 2101119 orphaned_objects_gc_test.go:512: - Total GC'd: 2101120--- PASS: TestOrphanedObjectsGCStressTest (10.46s)1121=== CONT TestIsValidUploadKey1122=== RUN TestIsValidUploadKey/narinfo1123=== PAUSE TestIsValidUploadKey/narinfo1124=== RUN TestIsValidUploadKey/nar_zst1125=== PAUSE TestIsValidUploadKey/nar_zst1126=== RUN TestIsValidUploadKey/nar_xz1127=== PAUSE TestIsValidUploadKey/nar_xz1128=== RUN TestIsValidUploadKey/nar_plain1129=== PAUSE TestIsValidUploadKey/nar_plain1130=== RUN TestIsValidUploadKey/listing1131=== PAUSE TestIsValidUploadKey/listing1132=== RUN TestIsValidUploadKey/build_log1133=== PAUSE TestIsValidUploadKey/build_log1134=== RUN TestIsValidUploadKey/build_log_home-manager_file1135=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1136=== RUN TestIsValidUploadKey/build_log_plus_in_name1137=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1138=== RUN TestIsValidUploadKey/build_log_question_mark1139=== PAUSE TestIsValidUploadKey/build_log_question_mark1140=== RUN TestIsValidUploadKey/build_log_equals1141=== PAUSE TestIsValidUploadKey/build_log_equals1142=== RUN TestIsValidUploadKey/realisation1143=== PAUSE TestIsValidUploadKey/realisation1144=== RUN TestIsValidUploadKey/realisation_plus_in_output1145=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1146=== RUN TestIsValidUploadKey/nix-cache-info1147=== PAUSE TestIsValidUploadKey/nix-cache-info1148=== RUN TestIsValidUploadKey/index.html1149=== PAUSE TestIsValidUploadKey/index.html1150=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1151=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1152=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1153=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1154=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1155=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1156=== RUN TestIsValidUploadKey/traversal1157=== PAUSE TestIsValidUploadKey/traversal1158=== RUN TestIsValidUploadKey/traversal_nar1159=== PAUSE TestIsValidUploadKey/traversal_nar1160=== RUN TestIsValidUploadKey/absolute1161=== PAUSE TestIsValidUploadKey/absolute1162=== RUN TestIsValidUploadKey/empty_key1163=== PAUSE TestIsValidUploadKey/empty_key1164=== RUN TestIsValidUploadKey/unknown_type1165=== PAUSE TestIsValidUploadKey/unknown_type1166=== CONT TestPendingClosureWriteTimeout1167=== RUN TestPendingClosureWriteTimeout/empty1168=== PAUSE TestPendingClosureWriteTimeout/empty1169=== RUN TestPendingClosureWriteTimeout/400_objects1170=== PAUSE TestPendingClosureWriteTimeout/400_objects1171=== RUN TestPendingClosureWriteTimeout/670k_objects1172=== PAUSE TestPendingClosureWriteTimeout/670k_objects1173=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1174=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1175=== CONT TestProxyWriteTimeout1176=== RUN TestProxyWriteTimeout/narinfo1177=== PAUSE TestProxyWriteTimeout/narinfo1178=== RUN TestProxyWriteTimeout/1_GiB_nar1179=== PAUSE TestProxyWriteTimeout/1_GiB_nar1180=== RUN TestProxyWriteTimeout/10_GiB_nar1181=== PAUSE TestProxyWriteTimeout/10_GiB_nar1182=== RUN TestProxyWriteTimeout/unknown_size1183=== PAUSE TestProxyWriteTimeout/unknown_size1184=== CONT TestParseSize1185--- PASS: TestParseSize (0.00s)1186=== CONT TestSkippedUploadsHandler11872026/10/01 10:46:05 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001188--- PASS: TestSkippedUploadsHandler (0.00s)1189=== CONT TestCompletedNarNotReofferedAcrossClosures1190--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.21s)1191=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11922026/10/01 10:46:05 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/01 10:46:05 INFO Aborted multipart uploads count=0 kept=011942026/10/01 10:46:05 WARN Force mode enabled - objects will be deleted immediately without grace period11952026/10/01 10:46:05 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=011962026/10/01 10:46:05 INFO Vacuumed table table=pending_closures11972026/10/01 10:46:05 INFO Vacuumed table table=pending_objects11982026/10/01 10:46:06 INFO Vacuumed table table=multipart_uploads11992026/10/01 10:46:06 INFO Vacuumed table table=closures12002026/10/01 10:46:06 INFO Vacuumed table table=objects1201--- PASS: TestGCSweepSkipsPendingObjects (2.67s)1202=== CONT TestService_Rustfstest12032026/10/01 10:46:06 INFO Received uploads request method=POST path=/api/pending_closures1204--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.61s)1205=== CONT TestClientIntegration12062026/10/01 10:46:06 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/01 10:46:06 INFO Aborted multipart uploads count=0 kept=012082026/10/01 10:46: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=012092026/10/01 10:46:06 INFO Vacuumed table table=pending_closures12102026/10/01 10:46:06 INFO Vacuumed table table=pending_objects12112026/10/01 10:46:06 INFO Vacuumed table table=multipart_uploads12122026/10/01 10:46:06 INFO Vacuumed table table=closures12132026/10/01 10:46:06 INFO Vacuumed table table=objects12142026/10/01 10:46:06 INFO Aborted multipart uploads count=0 kept=012152026/10/01 10:46:06 WARN Force mode enabled - objects will be deleted immediately without grace period12162026/10/01 10:46: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=012172026/10/01 10:46:06 INFO Vacuumed table table=pending_closures12182026/10/01 10:46:06 INFO Vacuumed table table=pending_objects12192026/10/01 10:46:06 INFO Vacuumed table table=multipart_uploads12202026/10/01 10:46:06 INFO Vacuumed table table=closures12212026/10/01 10:46:06 INFO Vacuumed table table=objects1222--- PASS: TestPushDedupSurvivesConcurrentGC (3.27s)1223=== CONT TestConnectWaitsForAPeerMigration12242026/10/01 10:46:07 INFO Aborted multipart uploads count=0 kept=012252026/10/01 10:46:07 WARN Force mode enabled - objects will be deleted immediately without grace period12262026/10/01 10:46:07 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=012272026/10/01 10:46:07 INFO Vacuumed table table=pending_closures12282026/10/01 10:46:07 INFO Vacuumed table table=pending_objects12292026/10/01 10:46:07 INFO Vacuumed table table=multipart_uploads12302026/10/01 10:46:07 INFO Vacuumed table table=closures12312026/10/01 10:46:07 INFO Vacuumed table table=objects1232--- PASS: TestGCMetrics (3.24s)1233=== CONT TestResolveDBConnectionString1234=== RUN TestResolveDBConnectionString/flag_wins1235=== PAUSE TestResolveDBConnectionString/flag_wins1236=== RUN TestResolveDBConnectionString/file_when_flag_empty1237=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1238=== RUN TestResolveDBConnectionString/missing_file_is_an_error1239=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1240=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1241=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1242=== RUN TestResolveDBConnectionString/nothing_configured1243=== PAUSE TestResolveDBConnectionString/nothing_configured1244=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1245--- PASS: TestGCBugBareHashReferences (3.60s)1246=== CONT TestClientFallsBackToClosures1247--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.60s)1248=== CONT TestClientPushesUseOnePush12492026/10/01 10:46:08 INFO lead: acquired remote=192.0.2.1:123412502026/10/01 10:46:08 INFO lead: released remote=192.0.2.1:12341251--- PASS: TestLeadEndsOnShutdown (3.68s)1252=== CONT TestPinProtectsFromGC12532026/10/01 10:46:08 INFO Received uploads request method=POST path=/api/pending_closures12542026/10/01 10:46:08 INFO Received uploads request method=POST path=/api/pending_closures12552026/10/01 10:46:09 INFO Received uploads request method=POST path=/api/pending_closures12562026/10/01 10:46:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12572026/10/01 10:46:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12582026/10/01 10:46:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLmY4Nzc1ZDhlLTg2NjAtNGM5ZS1hNDg4LTdiNmY1YzczMTA5OHgxNzkwODUxNTY5NDAyMzQyMDAw1259--- PASS: TestService_Rustfstest (3.68s)1260=== CONT TestClientSharedPathCommittedMidPush12612026/10/01 10:46:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLmY4Nzc1ZDhlLTg2NjAtNGM5ZS1hNDg4LTdiNmY1YzczMTA5OHgxNzkwODUxNTY5NDAyMzQyMDAw parts=11262--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (4.47s)1263=== CONT TestClientWithDependencies1264=== NAME TestClientIntegration1265 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-69215-2353416696/TestClientIntegration2123514672/002/store/dkh0hjpnb5f23b0a8sa03039x5z9vxik-test-file.txt12662026/10/01 10:46:10 INFO Received push request method=POST path=/api/pushes12672026/10/01 10:46:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12682026/10/01 10:46:10 INFO Uploading dkh0hjpnb5f23b0a8sa03039x5z9vxik-test-file.txt (152B)12692026/10/01 10:46:10 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12702026/10/01 10:46:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12712026/10/01 10:46:10 WARN Failed to register uploaded object key=dkh0hjpnb5f23b0a8sa03039x5z9vxik.ls error="server returned 404: 404 page not found\n"12722026/10/01 10:46:10 INFO Signed narinfos id=1 count=112732026/10/01 10:46:10 INFO Uploading 1 narinfos12742026/10/01 10:46:10 INFO Received complete push request method=POST path=/api/pushes/1/complete12752026/10/01 10:46:10 WARN Failed to register uploaded object key=dkh0hjpnb5f23b0a8sa03039x5z9vxik.narinfo error="server returned 404: 404 page not found\n"12762026/10/01 10:46:10 INFO Upload complete. (141ms)12772026/10/01 10:46:10 INFO All 1 paths already cached1278 client_integration_test.go:312: Retrieved narinfo from S3:1279 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientIntegration2123514672/002/store/dkh0hjpnb5f23b0a8sa03039x5z9vxik-test-file.txt1280 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1281 Compression: zstd1282 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11283 NarSize: 1521284 References: 1285 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11286 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1287 client_integration_test.go:313: Decompressed .ls content (64 bytes):1288 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1289 client_integration_test.go:316: Testing garbage collection...12902026/10/01 10:46:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures12912026/10/01 10:46:10 INFO Garbage collection started12922026/10/01 10:46:10 INFO Aborted multipart uploads count=0 kept=012932026/10/01 10:46:10 WARN Force mode enabled - objects will be deleted immediately without grace period12942026/10/01 10:46:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12952026/10/01 10:46:10 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=012962026/10/01 10:46:10 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTk2ZTQ0ZTEtN2YwYi00ZTkzLWIwNTMtMWE5M2QzZWE2MTBjLmEyOWY1OGU3LTY4NzYtNDgzOC04YjIyLWVhNGQzMWM4Mjk5OXgxNzkwODUxNTY4NTk1MjI2MDAw parts=1212972026/10/01 10:46:10 INFO Received uploads request method=POST path=/api/pending_closures1298--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.45s)1299=== CONT TestClientMultipleUploads13002026/10/01 10:46:10 INFO Vacuumed table table=pending_closures13012026/10/01 10:46:10 INFO Vacuumed table table=pending_objects13022026/10/01 10:46:10 INFO Vacuumed table table=multipart_uploads13032026/10/01 10:46:10 INFO Vacuumed table table=closures13042026/10/01 10:46:10 INFO Vacuumed table table=objects13052026/10/01 10:46:11 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/01 10:46:11 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/01 10:46:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13082026/10/01 10:46:11 INFO Uploading 6nq3wnp6f34fgawr6ikjw99ndiajhxv9-a (248B)13092026/10/01 10:46:11 INFO Uploading vvliq015dvz2is34vdcbhzvwad593w5v-shared-dep (136B)13102026/10/01 10:46:11 WARN Failed to register uploaded object key=6nq3wnp6f34fgawr6ikjw99ndiajhxv9.ls error="server returned 404: 404 page not found\n"13112026/10/01 10:46:11 WARN Failed to register uploaded object key=vvliq015dvz2is34vdcbhzvwad593w5v.ls error="server returned 404: 404 page not found\n"13122026/10/01 10:46:11 WARN Failed to register uploaded object key=qa6ffg6dvz1f1wlq08jhj4vjwcazm3rr.ls error="server returned 404: 404 page not found\n"13132026/10/01 10:46:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13142026/10/01 10:46:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13152026/10/01 10:46:11 WARN Failed to register uploaded object key=nar/18k9ij3nij07x7bp71rhnysirhq35i7qn7nlg3bwrqwygbhzvl73.nar.zst error="server returned 404: 404 page not found\n"13162026/10/01 10:46:11 INFO Signed narinfos id=1 count=213172026/10/01 10:46:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13182026/10/01 10:46:11 INFO Signed narinfos id=2 count=213192026/10/01 10:46:11 INFO Uploading 4 narinfos13202026/10/01 10:46:11 WARN Failed to register uploaded object key=vvliq015dvz2is34vdcbhzvwad593w5v.narinfo error="server returned 404: 404 page not found\n"13212026/10/01 10:46:11 WARN Failed to register uploaded object key=qa6ffg6dvz1f1wlq08jhj4vjwcazm3rr.narinfo error="server returned 404: 404 page not found\n"13222026/10/01 10:46:11 WARN Failed to register uploaded object key=6nq3wnp6f34fgawr6ikjw99ndiajhxv9.narinfo error="server returned 404: 404 page not found\n"13232026/10/01 10:46:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13242026/10/01 10:46:11 WARN Failed to register uploaded object key=vvliq015dvz2is34vdcbhzvwad593w5v.narinfo error="server returned 404: 404 page not found\n"13252026/10/01 10:46:11 INFO Completed upload id=113262026/10/01 10:46:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13272026/10/01 10:46:11 INFO Completed upload id=213282026/10/01 10:46:11 INFO Upload complete. (96ms)1329=== NAME TestClientFallsBackToClosures1330 client_pushes_test.go:112: Retrieved narinfo from S3:1331 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientFallsBackToClosures2371074169/001/store/vvliq015dvz2is34vdcbhzvwad593w5v-shared-dep1332 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1333 Compression: zstd1334 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821335 NarSize: 1361336 References: 1337 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1338 client_pushes_test.go:112: Retrieved narinfo from S3:1339 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientFallsBackToClosures2371074169/001/store/6nq3wnp6f34fgawr6ikjw99ndiajhxv9-a1340 URL: nar/18k9ij3nij07x7bp71rhnysirhq35i7qn7nlg3bwrqwygbhzvl73.nar.zst1341 Compression: zstd1342 NarHash: sha256:18k9ij3nij07x7bp71rhnysirhq35i7qn7nlg3bwrqwygbhzvl731343 NarSize: 2481344 References: /nix/var/nix/builds/nix-69215-2353416696/TestClientFallsBackToClosures2371074169/001/store/vvliq015dvz2is34vdcbhzvwad593w5v-shared-dep1345 CA: text:sha256:0dk781qaxw5r1knq6a9ffl4slhm8ji4k6w3ygp0q0sf19cm5wydq1346 client_pushes_test.go:112: Retrieved narinfo from S3:1347 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientFallsBackToClosures2371074169/001/store/qa6ffg6dvz1f1wlq08jhj4vjwcazm3rr-b1348 URL: nar/18k9ij3nij07x7bp71rhnysirhq35i7qn7nlg3bwrqwygbhzvl73.nar.zst1349 Compression: zstd1350 NarHash: sha256:18k9ij3nij07x7bp71rhnysirhq35i7qn7nlg3bwrqwygbhzvl731351 NarSize: 2481352 References: /nix/var/nix/builds/nix-69215-2353416696/TestClientFallsBackToClosures2371074169/001/store/vvliq015dvz2is34vdcbhzvwad593w5v-shared-dep1353 CA: text:sha256:0dk781qaxw5r1knq6a9ffl4slhm8ji4k6w3ygp0q0sf19cm5wydq1354--- PASS: TestClientFallsBackToClosures (4.11s)1355=== CONT TestService_ReadScope_PublicByDefault1356--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.74s)1357=== CONT TestClientErrorHandling1358=== RUN TestClientErrorHandling/InvalidStorePath1359=== PAUSE TestClientErrorHandling/InvalidStorePath1360=== RUN TestClientErrorHandling/InvalidAuthToken1361=== PAUSE TestClientErrorHandling/InvalidAuthToken1362=== RUN TestClientErrorHandling/ServerNotAvailable1363=== PAUSE TestClientErrorHandling/ServerNotAvailable1364=== CONT TestClientCADerivations13652026/10/01 10:46:11 INFO Received push request method=POST path=/api/pushes13662026/10/01 10:46:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13672026/10/01 10:46:11 INFO Uploading mnw2g3fc84jqw3s3721wkbrigwfv1r9p-a (248B)13682026/10/01 10:46:11 INFO Uploading g895yaihzbr326l20nghrixgpcgc2wl8-shared-dep (136B)1369=== NAME TestPinProtectsFromGC1370 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-69215-2353416696/TestPinProtectsFromGC2569468504/001/store/mls1dva22cpcry1nlhc94m4wc8542bzh-pinned-file.txt1371 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-69215-2353416696/TestPinProtectsFromGC2569468504/001/store/w1x8jh1kh0p59cxrx9lksp32aj7rll32-unpinned-file.txt13722026/10/01 10:46:12 WARN Failed to register uploaded object key=mnw2g3fc84jqw3s3721wkbrigwfv1r9p.ls error="server returned 404: 404 page not found\n"13732026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13742026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1xvkhxnd1247pzn0bwcb6gqkc010pxnwmamcgi9k15vy8pbbfdx7.nar.zst error="server returned 404: 404 page not found\n"13752026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/10/01 10:46:12 WARN Failed to register uploaded object key=g895yaihzbr326l20nghrixgpcgc2wl8.ls error="server returned 404: 404 page not found\n"13772026/10/01 10:46:12 WARN Failed to register uploaded object key=jj1jm7x4f39rx1w4i9jf7vp7438qf1pl.ls error="server returned 404: 404 page not found\n"13782026/10/01 10:46:12 INFO Signed narinfos id=1 count=313792026/10/01 10:46:12 INFO Uploading 3 narinfos13802026/10/01 10:46:12 WARN Failed to register uploaded object key=g895yaihzbr326l20nghrixgpcgc2wl8.narinfo error="server returned 404: 404 page not found\n"13812026/10/01 10:46:12 WARN Failed to register uploaded object key=jj1jm7x4f39rx1w4i9jf7vp7438qf1pl.narinfo error="server returned 404: 404 page not found\n"13822026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13832026/10/01 10:46:12 WARN Failed to register uploaded object key=mnw2g3fc84jqw3s3721wkbrigwfv1r9p.narinfo error="server returned 404: 404 page not found\n"13842026/10/01 10:46:12 INFO Upload complete. (120ms)1385=== NAME TestClientPushesUseOnePush1386 client_pushes_test.go:97: Retrieved narinfo from S3:1387 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientPushesUseOnePush3286410851/001/store/g895yaihzbr326l20nghrixgpcgc2wl8-shared-dep1388 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1389 Compression: zstd1390 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821391 NarSize: 1361392 References: 1393 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1394 client_pushes_test.go:97: Retrieved narinfo from S3:1395 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientPushesUseOnePush3286410851/001/store/mnw2g3fc84jqw3s3721wkbrigwfv1r9p-a1396 URL: nar/1xvkhxnd1247pzn0bwcb6gqkc010pxnwmamcgi9k15vy8pbbfdx7.nar.zst1397 Compression: zstd1398 NarHash: sha256:1xvkhxnd1247pzn0bwcb6gqkc010pxnwmamcgi9k15vy8pbbfdx71399 NarSize: 2481400 References: /nix/var/nix/builds/nix-69215-2353416696/TestClientPushesUseOnePush3286410851/001/store/g895yaihzbr326l20nghrixgpcgc2wl8-shared-dep1401 CA: text:sha256:0cq45vhx5fqgyrwjnbax0vyzl24vnnsi9j1bnh516bnahfa9zzns1402 client_pushes_test.go:97: Retrieved narinfo from S3:1403 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientPushesUseOnePush3286410851/001/store/jj1jm7x4f39rx1w4i9jf7vp7438qf1pl-b1404 URL: nar/1xvkhxnd1247pzn0bwcb6gqkc010pxnwmamcgi9k15vy8pbbfdx7.nar.zst1405 Compression: zstd1406 NarHash: sha256:1xvkhxnd1247pzn0bwcb6gqkc010pxnwmamcgi9k15vy8pbbfdx71407 NarSize: 2481408 References: /nix/var/nix/builds/nix-69215-2353416696/TestClientPushesUseOnePush3286410851/001/store/g895yaihzbr326l20nghrixgpcgc2wl8-shared-dep1409 CA: text:sha256:0cq45vhx5fqgyrwjnbax0vyzl24vnnsi9j1bnh516bnahfa9zzns14102026/10/01 10:46:12 INFO Received push request method=POST path=/api/pushes1411--- PASS: TestClientPushesUseOnePush (4.25s)1412=== CONT TestCacheStatsHandler14132026/10/01 10:46:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14142026/10/01 10:46:12 INFO Uploading mls1dva22cpcry1nlhc94m4wc8542bzh-pinned-file.txt (128B)14152026/10/01 10:46:12 WARN Failed to register uploaded object key=mls1dva22cpcry1nlhc94m4wc8542bzh.ls error="server returned 404: 404 page not found\n"14162026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14172026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14182026/10/01 10:46:12 INFO Signed narinfos id=1 count=114192026/10/01 10:46:12 INFO Uploading 1 narinfos14202026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/1/complete14212026/10/01 10:46:12 WARN Failed to register uploaded object key=mls1dva22cpcry1nlhc94m4wc8542bzh.narinfo error="server returned 404: 404 page not found\n"14222026/10/01 10:46:12 INFO Upload complete. (170ms)14232026/10/01 10:46:12 INFO Received push request method=POST path=/api/pushes14242026/10/01 10:46:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14252026/10/01 10:46:12 INFO Uploading w1x8jh1kh0p59cxrx9lksp32aj7rll32-unpinned-file.txt (128B)14262026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14272026/10/01 10:46:12 INFO Signed narinfos id=2 count=114282026/10/01 10:46:12 INFO Uploading 1 narinfos14292026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14302026/10/01 10:46:12 WARN Failed to register uploaded object key=w1x8jh1kh0p59cxrx9lksp32aj7rll32.ls error="server returned 404: 404 page not found\n"14312026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/2/complete14322026/10/01 10:46:12 WARN Failed to register uploaded object key=w1x8jh1kh0p59cxrx9lksp32aj7rll32.narinfo error="server returned 404: 404 page not found\n"14332026/10/01 10:46:12 INFO Upload complete. (63ms)14342026/10/01 10:46:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures14352026/10/01 10:46:12 INFO Garbage collection started14362026/10/01 10:46:12 INFO Aborted multipart uploads count=0 kept=014372026/10/01 10:46:12 WARN Force mode enabled - objects will be deleted immediately without grace period14382026/10/01 10:46:12 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=014392026/10/01 10:46:12 INFO Vacuumed table table=pending_closures14402026/10/01 10:46:12 INFO Received push request method=POST path=/api/pushes14412026/10/01 10:46:12 INFO Vacuumed table table=pending_objects14422026/10/01 10:46:12 INFO Vacuumed table table=multipart_uploads14432026/10/01 10:46:12 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14442026/10/01 10:46:12 INFO Uploading 3mhzdlbln8igp3f8hnwss53jzsf9gvy6-top (256B)14452026/10/01 10:46:12 INFO Uploading 5j3b4mnfbdihkzqv2wapsgyy52fyc88j-shared-dep (136B)14462026/10/01 10:46:12 INFO Vacuumed table table=closures14472026/10/01 10:46:12 WARN Failed to register uploaded object key=5j3b4mnfbdihkzqv2wapsgyy52fyc88j.ls error="server returned 404: 404 page not found\n"14482026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14492026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1ppfqjnpxm8jl93m65cx0vflfpd010l0qxx7cv4vfi34al39z54d.nar.zst error="server returned 404: 404 page not found\n"14502026/10/01 10:46:12 WARN Failed to register uploaded object key=3mhzdlbln8igp3f8hnwss53jzsf9gvy6.ls error="server returned 404: 404 page not found\n"14512026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/10/01 10:46:12 INFO Signed narinfos id=1 count=214532026/10/01 10:46:12 INFO Uploading 2 narinfos14542026/10/01 10:46:12 INFO Vacuumed table table=objects14552026/10/01 10:46:12 WARN Failed to register uploaded object key=5j3b4mnfbdihkzqv2wapsgyy52fyc88j.narinfo error="server returned 404: 404 page not found\n"14562026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/1/complete14572026/10/01 10:46:12 WARN Failed to register uploaded object key=3mhzdlbln8igp3f8hnwss53jzsf9gvy6.narinfo error="server returned 404: 404 page not found\n"14582026/10/01 10:46:12 INFO Upload complete. (142ms)1459=== NAME TestClientSharedPathCommittedMidPush1460 client_integration_test.go:680: Retrieved narinfo from S3:1461 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientSharedPathCommittedMidPush2286677559/001/store/5j3b4mnfbdihkzqv2wapsgyy52fyc88j-shared-dep1462 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1463 Compression: zstd1464 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821465 NarSize: 1361466 References: 1467 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1468 client_integration_test.go:680: Retrieved narinfo from S3:1469 StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientSharedPathCommittedMidPush2286677559/001/store/3mhzdlbln8igp3f8hnwss53jzsf9gvy6-top1470 URL: nar/1ppfqjnpxm8jl93m65cx0vflfpd010l0qxx7cv4vfi34al39z54d.nar.zst1471 Compression: zstd1472 NarHash: sha256:1ppfqjnpxm8jl93m65cx0vflfpd010l0qxx7cv4vfi34al39z54d1473 NarSize: 2561474 References: /nix/var/nix/builds/nix-69215-2353416696/TestClientSharedPathCommittedMidPush2286677559/001/store/5j3b4mnfbdihkzqv2wapsgyy52fyc88j-shared-dep1475 CA: text:sha256:042xy3yyf7p6w7439vs0wg7rpc5zh3p527bhh47r9ima86kdgixy1476--- PASS: TestClientSharedPathCommittedMidPush (2.78s)1477=== CONT TestCacheConfigHandler1478=== RUN TestCacheConfigHandler/full_config,_no_issuer1479=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1480=== RUN TestCacheConfigHandler/no_cache_url_configured1481=== PAUSE TestCacheConfigHandler/no_cache_url_configured1482=== RUN TestCacheConfigHandler/no_signing_keys1483=== PAUSE TestCacheConfigHandler/no_signing_keys1484=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1485=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1486=== CONT TestPush_RejectsBadRequests1487=== NAME TestClientMultipleUploads1488 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-69215-2353416696/TestClientMultipleUploads1471941625/001/store/a43ragj1pkp2q74i1053mp91lfsq0syr-test-file-0.txt1489 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-69215-2353416696/TestClientMultipleUploads1471941625/001/store/4wz5p7lsih00ql23q3q6b40fiqlcra9p-test-file-1.txt1490=== NAME TestClientWithDependencies1491 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-69215-2353416696/TestClientWithDependencies2129762067/001/store/dbvp0vfm2d8bgp6109l05rliisn1rxjj-test-script14922026/10/01 10:46:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01493=== NAME TestClientIntegration1494 client_integration_test.go:323: Objects in database after GC:1495 client_integration_test.go:323: Successfully deleted all objects with GC --force1496--- PASS: TestClientIntegration (6.44s)1497=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1498=== NAME TestClientMultipleUploads1499 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-69215-2353416696/TestClientMultipleUploads1471941625/001/store/wmlkihgc01mn23lsapdr8aija2cfgm6n-test-file-2.txt1500=== NAME TestClientWithDependencies1501 client_integration_test.go:615: Found 1 dependencies (including self)15022026/10/01 10:46:12 INFO Received push request method=POST path=/api/pushes15032026/10/01 10:46:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15042026/10/01 10:46:12 INFO Uploading wmlkihgc01mn23lsapdr8aija2cfgm6n-test-file-2.txt (160B)15052026/10/01 10:46:12 INFO Uploading 4wz5p7lsih00ql23q3q6b40fiqlcra9p-test-file-1.txt (160B)15062026/10/01 10:46:12 INFO Uploading a43ragj1pkp2q74i1053mp91lfsq0syr-test-file-0.txt (160B)15072026/10/01 10:46:12 INFO Received push request method=POST path=/api/pushes15082026/10/01 10:46:12 WARN Failed to register uploaded object key=4wz5p7lsih00ql23q3q6b40fiqlcra9p.ls error="server returned 404: 404 page not found\n"15092026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15102026/10/01 10:46:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15112026/10/01 10:46:12 INFO Uploading dbvp0vfm2d8bgp6109l05rliisn1rxjj-test-script (136B)15122026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15132026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15142026/10/01 10:46:12 WARN Failed to register uploaded object key=a43ragj1pkp2q74i1053mp91lfsq0syr.ls error="server returned 404: 404 page not found\n"15152026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15162026/10/01 10:46:12 WARN Failed to register uploaded object key=wmlkihgc01mn23lsapdr8aija2cfgm6n.ls error="server returned 404: 404 page not found\n"15172026/10/01 10:46:12 INFO Signed narinfos id=1 count=315182026/10/01 10:46:12 INFO Uploading 3 narinfos15192026/10/01 10:46:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15202026/10/01 10:46:12 WARN Failed to register uploaded object key=a43ragj1pkp2q74i1053mp91lfsq0syr.narinfo error="server returned 404: 404 page not found\n"15212026/10/01 10:46:12 WARN Failed to register uploaded object key=wmlkihgc01mn23lsapdr8aija2cfgm6n.narinfo error="server returned 404: 404 page not found\n"15222026/10/01 10:46:12 WARN Failed to register uploaded object key=dbvp0vfm2d8bgp6109l05rliisn1rxjj.ls error="server returned 404: 404 page not found\n"15232026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/1/complete15242026/10/01 10:46:12 WARN Failed to register uploaded object key=4wz5p7lsih00ql23q3q6b40fiqlcra9p.narinfo error="server returned 404: 404 page not found\n"15252026/10/01 10:46:12 WARN Failed to register uploaded object key=log/ksvrcg9ycigyzhyycm7yx30ypp6wy0bh-test-script.drv error="server returned 404: 404 page not found\n"15262026/10/01 10:46:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15272026/10/01 10:46:12 INFO Signed narinfos id=1 count=115282026/10/01 10:46:12 INFO Uploading 1 narinfos15292026/10/01 10:46:12 INFO Upload complete. (122ms)1530=== NAME TestClientMultipleUploads1531 client_integration_test.go:369: Uploaded 3 paths in 157.480084ms15322026/10/01 10:46:12 INFO Received complete push request method=POST path=/api/pushes/1/complete15332026/10/01 10:46:12 WARN Failed to register uploaded object key=dbvp0vfm2d8bgp6109l05rliisn1rxjj.narinfo error="server returned 404: 404 page not found\n"15342026/10/01 10:46:12 INFO Upload complete. (148ms)1535=== NAME TestClientWithDependencies1536 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-69215-2353416696/TestClientWithDependencies2129762067/001/store) requires matching store prefix1537--- PASS: TestClientMultipleUploads (2.14s)1538=== CONT TestService_ReadAuthMiddleware1539--- PASS: TestClientWithDependencies (3.15s)1540=== CONT TestService_RequireScope_OIDC15412026/10/01 10:46:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65320/oidc1542--- PASS: TestService_ReadScope_PublicByDefault (1.04s)1543=== CONT TestService_AuthMiddleware_OIDC15442026/10/01 10:46:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65324/oidc15452026/10/01 10:46:13 WARN Rate limiter enabled after throttle name=s3-test rate=515462026/10/01 10:46:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1547=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1548 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101549 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001550--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.04s)1551=== CONT TestService_AuthMiddleware_MTLSProxyHeader1552--- PASS: TestCacheStatsHandler (1.21s)1553=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15542026/10/01 10:46:13 INFO Received uploads request method=POST path=/1555=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15562026/10/01 10:46:13 INFO Received complete multipart upload request method=POST path=/1557=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15582026/10/01 10:46:13 INFO Received request for more parts method=POST path=/1559=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15602026/10/01 10:46:13 INFO Received uploads request method=POST path=/1561--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1562 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1563 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1564 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1565 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1566=== CONT TestIsValidCachePath/narinfo1567=== CONT TestIsValidCachePath/index.html1568=== CONT TestIsValidCachePath/traversal_parent1569=== CONT TestIsValidCachePath/nix-cache-info1570=== CONT TestIsValidCachePath/realisation1571=== CONT TestIsValidCachePath/log1572=== CONT TestIsValidCachePath/ls1573=== CONT TestIsValidCachePath/nar_uncompressed1574=== CONT TestIsValidCachePath/nar_bz21575=== CONT TestIsValidCachePath/nar_xz1576=== CONT TestIsValidCachePath/nar_zst1577=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1578=== CONT TestIsValidCachePath/empty1579=== CONT TestIsValidCachePath/short_hash1580=== CONT TestIsValidCachePath/wrong_extension1581=== CONT TestIsValidCachePath/leading_slash1582=== CONT TestIsValidCachePath/invalid_char_u1583=== CONT TestIsValidCachePath/random_path1584=== CONT TestIsValidCachePath/invalid_char_e1585=== CONT TestIsValidCachePath/traversal_in_middle1586--- PASS: TestIsValidCachePath (0.00s)1587 --- PASS: TestIsValidCachePath/narinfo (0.00s)1588 --- PASS: TestIsValidCachePath/index.html (0.00s)1589 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1590 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1591 --- PASS: TestIsValidCachePath/realisation (0.00s)1592 --- PASS: TestIsValidCachePath/log (0.00s)1593 --- PASS: TestIsValidCachePath/ls (0.00s)1594 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1595 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1596 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1597 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1598 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1599 --- PASS: TestIsValidCachePath/empty (0.00s)1600 --- PASS: TestIsValidCachePath/short_hash (0.00s)1601 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1602 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1603 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1604 --- PASS: TestIsValidCachePath/random_path (0.00s)1605 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1606 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1607=== CONT TestParseSingleRange/none1608=== CONT TestParseSingleRange/open-ended1609=== CONT TestParseSingleRange/start_far_past_EOF1610=== CONT TestParseSingleRange/start_past_EOF1611=== CONT TestParseSingleRange/single_byte1612=== CONT TestParseSingleRange/suffix_exceeds_size1613=== CONT TestParseSingleRange/suffix1614=== CONT TestParseSingleRange/end_clamped_to_size1615=== CONT TestParseSingleRange/closed1616=== CONT TestParseSingleRange/multi-range_ignored1617=== CONT TestParseSingleRange/malformed_both_empty1618=== CONT TestParseSingleRange/malformed_no_dash1619=== CONT TestParseSingleRange/malformed_end_before_start1620=== CONT TestParseSingleRange/unknown_unit1621--- PASS: TestParseSingleRange (0.00s)1622 --- PASS: TestParseSingleRange/none (0.00s)1623 --- PASS: TestParseSingleRange/open-ended (0.00s)1624 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1625 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1626 --- PASS: TestParseSingleRange/single_byte (0.00s)1627 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1628 --- PASS: TestParseSingleRange/suffix (0.00s)1629 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1630 --- PASS: TestParseSingleRange/closed (0.00s)1631 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1632 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1633 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1634 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1635 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1636=== CONT TestServerTLSConfig/no_client_CA1637=== CONT TestServerTLSConfig/not_a_PEM_file1638=== CONT TestServerTLSConfig/missing_CA_file1639--- PASS: TestServerTLSConfig (0.00s)1640 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1641 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1642 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1643=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16442026/10/01 10:46:13 INFO Received uploads request method=POST path=/1645=== NAME TestClientCADerivations1646 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-69215-2353416696/TestClientCADerivations483297322/001/store/khvb7libvcg9cnd7xsa28g3h2mxh0qgn-ca-test1647 client_ca_test.go:139: Found 1 dependencies (including self)1648=== RUN TestPush_RejectsBadRequests/root_not_in_objects1649=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1650=== RUN TestPush_RejectsBadRequests/no_roots1651=== PAUSE TestPush_RejectsBadRequests/no_roots1652=== RUN TestPush_RejectsBadRequests/no_objects1653=== PAUSE TestPush_RejectsBadRequests/no_objects1654=== RUN TestPush_RejectsBadRequests/bad_root1655=== PAUSE TestPush_RejectsBadRequests/bad_root1656=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16572026/10/01 10:46:13 INFO Received request for more parts method=POST path=/1658=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16592026/10/01 10:46:13 INFO Received complete multipart upload request method=POST path=/1660=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16612026/10/01 10:46:13 INFO Received push request method=POST path=/api/pushes1662--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1663 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1664 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1665 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1666=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16672026/10/01 10:46:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16682026/10/01 10:46:13 INFO Uploading khvb7libvcg9cnd7xsa28g3h2mxh0qgn-ca-test (144B)16692026/10/01 10:46:13 WARN Failed to register uploaded object key=khvb7libvcg9cnd7xsa28g3h2mxh0qgn.ls error="server returned 404: 404 page not found\n"16702026/10/01 10:46:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16712026/10/01 10:46:13 WARN Failed to register uploaded object key=log/1k6rmlmy7bdbapnv3ywsyl9xhs0a2m4i-ca-test.drv error="server returned 404: 404 page not found\n"16722026/10/01 10:46:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16732026/10/01 10:46:13 INFO Signed narinfos id=1 count=116742026/10/01 10:46:13 INFO Uploading 1 narinfos16752026/10/01 10:46:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16762026/10/01 10:46:13 WARN mTLS auth: bound subjects configured but subject DN unavailable16772026/10/01 10:46:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1678--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.00s)1679=== CONT TestIsValidUploadKey/narinfo1680=== CONT TestIsValidUploadKey/realisation_plus_in_output1681=== CONT TestIsValidUploadKey/realisation1682=== CONT TestIsValidUploadKey/nix-cache-info1683=== CONT TestIsValidUploadKey/build_log_equals1684=== CONT TestIsValidUploadKey/build_log_question_mark1685=== CONT TestIsValidUploadKey/build_log_plus_in_name1686=== CONT TestIsValidUploadKey/build_log_home-manager_file1687=== CONT TestIsValidUploadKey/build_log1688=== CONT TestIsValidUploadKey/listing1689=== CONT TestIsValidUploadKey/nar_plain1690=== CONT TestIsValidUploadKey/nar_xz1691=== CONT TestIsValidUploadKey/nar_zst1692=== CONT TestIsValidUploadKey/traversal1693=== CONT TestIsValidUploadKey/unknown_type1694=== CONT TestIsValidUploadKey/empty_key1695=== CONT TestIsValidUploadKey/absolute1696=== CONT TestIsValidUploadKey/traversal_nar1697=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1698=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1699=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1700=== CONT TestIsValidUploadKey/index.html1701--- PASS: TestIsValidUploadKey (0.00s)1702 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1703 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1704 --- PASS: TestIsValidUploadKey/realisation (0.00s)1705 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1706 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1707 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1708 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1709 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1710 --- PASS: TestIsValidUploadKey/build_log (0.00s)1711 --- PASS: TestIsValidUploadKey/listing (0.00s)1712 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1713 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1714 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1715 --- PASS: TestIsValidUploadKey/traversal (0.00s)1716 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1717 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1718 --- PASS: TestIsValidUploadKey/absolute (0.00s)1719 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1720 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1721 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1722 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1723 --- PASS: TestIsValidUploadKey/index.html (0.00s)1724=== CONT TestPendingClosureWriteTimeout/empty1725=== CONT TestPendingClosureWriteTimeout/670k_objects1726=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17272026/10/01 10:46:13 INFO Received complete push request method=POST path=/api/pushes/1/complete17282026/10/01 10:46:13 WARN Failed to register uploaded object key=khvb7libvcg9cnd7xsa28g3h2mxh0qgn.narinfo error="server returned 404: 404 page not found\n"17292026/10/01 10:46:13 INFO Upload complete. (158ms)1730=== NAME TestClientCADerivations1731 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-69215-2353416696/TestClientCADerivations483297322/001/store/khvb7libvcg9cnd7xsa28g3h2mxh0qgn-ca-test1732 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1733 Compression: zstd1734 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1735 NarSize: 1441736 References: 1737 Deriver: /nix/var/nix/builds/nix-69215-2353416696/TestClientCADerivations483297322/001/store/1k6rmlmy7bdbapnv3ywsyl9xhs0a2m4i-ca-test.drv1738 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1739 client_ca_test.go:185: Checking for realisation files in S3...1740 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1741 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1742 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket75?endpoint=http://localhost:64963®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-69215-2353416696/TestClientCADerivations483297322/001/store'1743 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11744--- PASS: TestClientCADerivations (1.74s)1745=== CONT TestPendingClosureWriteTimeout/400_objects1746=== CONT TestProxyWriteTimeout/narinfo1747=== CONT TestProxyWriteTimeout/10_GiB_nar1748=== CONT TestProxyWriteTimeout/unknown_size1749=== CONT TestProxyWriteTimeout/1_GiB_nar1750--- PASS: TestProxyWriteTimeout (0.00s)1751 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1752 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1753 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1754 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1755=== CONT TestResolveDBConnectionString/flag_wins1756=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1757=== CONT TestResolveDBConnectionString/nothing_configured1758=== CONT TestResolveDBConnectionString/missing_file_is_an_error1759=== CONT TestResolveDBConnectionString/file_when_flag_empty1760=== CONT TestClientErrorHandling/InvalidStorePath1761--- PASS: TestResolveDBConnectionString (0.03s)1762 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1763 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1764 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1765 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1766 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1767--- PASS: TestService_ReadAuthMiddleware (1.00s)1768=== CONT TestClientErrorHandling/ServerNotAvailable17692026/10/01 10:46:14 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/present1770=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1771=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1772=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1773=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1774=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1775=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1776=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1777=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1778=== CONT TestClientErrorHandling/InvalidAuthToken17792026/10/01 10:46:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.879931ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1780=== RUN TestService_RequireScope_OIDC/builder_may_write1781=== PAUSE TestService_RequireScope_OIDC/builder_may_write1782=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1783=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1784=== RUN TestService_RequireScope_OIDC/ops_may_admin1785=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1786=== RUN TestService_RequireScope_OIDC/ops_may_not_write1787=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1788=== RUN TestService_RequireScope_OIDC/reader_may_not_write1789=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1790=== RUN TestService_RequireScope_OIDC/static_token_may_admin1791=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1792=== RUN TestService_RequireScope_OIDC/static_token_may_write1793=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1794=== RUN TestService_RequireScope_OIDC/reader_may_read1795=== PAUSE TestService_RequireScope_OIDC/reader_may_read1796=== RUN TestService_RequireScope_OIDC/writer_implies_read1797=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1798=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1799=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1800=== CONT TestCacheConfigHandler/full_config,_no_issuer1801=== CONT TestCacheConfigHandler/no_signing_keys1802=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1803=== CONT TestCacheConfigHandler/no_cache_url_configured1804--- PASS: TestCacheConfigHandler (0.00s)1805 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1806 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1807 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1808 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1809=== CONT TestPush_RejectsBadRequests/root_not_in_objects18102026/10/01 10:46:14 INFO Received push request method=POST path=/api/pushes1811=== CONT TestPush_RejectsBadRequests/no_objects18122026/10/01 10:46:14 INFO Received push request method=POST path=/api/pushes1813=== CONT TestPush_RejectsBadRequests/bad_root18142026/10/01 10:46:14 INFO Received push request method=POST path=/api/pushes1815=== CONT TestPush_RejectsBadRequests/no_roots18162026/10/01 10:46:14 INFO Received push request method=POST path=/api/pushes1817=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1818--- PASS: TestPush_RejectsBadRequests (0.94s)1819 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1820 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1821 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1822 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1823=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18242026/10/01 10:46:14 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]1825=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1826=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18272026/10/01 10:46:14 WARN Authentication failed token_preview=eyJhbGciOi...siiZTl8g0A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1828=== CONT TestService_RequireScope_OIDC/builder_may_write1829=== CONT TestService_RequireScope_OIDC/static_token_may_admin1830=== CONT TestService_RequireScope_OIDC/reader_may_not_write1831=== CONT TestService_RequireScope_OIDC/ops_may_not_write1832=== CONT TestService_RequireScope_OIDC/ops_may_admin1833=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1834=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1835=== CONT TestService_RequireScope_OIDC/static_token_may_write1836=== CONT TestService_RequireScope_OIDC/writer_implies_read1837=== CONT TestService_RequireScope_OIDC/reader_may_read1838--- PASS: TestService_AuthMiddleware_OIDC (1.09s)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--- PASS: TestService_RequireScope_OIDC (1.32s)1844 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1845 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1846 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1847 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1848 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1849 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1850 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1851 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1852 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1853 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)18542026/10/01 10:46:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.766579ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18552026/10/01 10:46:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018562026/10/01 10:46:14 INFO Received create pin request method=POST path=/api/pins/myapp18572026/10/01 10:46:14 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-69215-2353416696/TestPinProtectsFromGC2569468504/001/store/mls1dva22cpcry1nlhc94m4wc8542bzh-pinned-file.txt narinfo_key=mls1dva22cpcry1nlhc94m4wc8542bzh.narinfo18582026/10/01 10:46:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures18592026/10/01 10:46:14 INFO Garbage collection started18602026/10/01 10:46:14 INFO Aborted multipart uploads count=0 kept=018612026/10/01 10:46:14 WARN Force mode enabled - objects will be deleted immediately without grace period18622026/10/01 10:46:14 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=018632026/10/01 10:46:14 INFO Vacuumed table table=pending_closures18642026/10/01 10:46:14 INFO Vacuumed table table=pending_objects18652026/10/01 10:46:14 INFO Vacuumed table table=multipart_uploads18662026/10/01 10:46:14 INFO Vacuumed table table=closures18672026/10/01 10:46:14 INFO Vacuumed table table=objects1868--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.21s)18692026/10/01 10:46:14 INFO Received uploads request method=POST path=/api/pending_closures18702026/10/01 10:46:14 INFO Aborted multipart uploads count=0 kept=018712026/10/01 10:46:14 WARN Force mode enabled - objects will be deleted immediately without grace period18722026/10/01 10:46:14 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=018732026/10/01 10:46:14 INFO Vacuumed table table=pending_closures18742026/10/01 10:46:14 INFO Vacuumed table table=pending_objects18752026/10/01 10:46:14 INFO Vacuumed table table=multipart_uploads18762026/10/01 10:46:14 INFO Vacuumed table table=closures18772026/10/01 10:46:14 INFO Vacuumed table table=objects18782026/10/01 10:46:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=724.143564ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18792026/10/01 10:46:14 INFO Received uploads request method=POST path=/api/pending_closures18802026/10/01 10:46:14 INFO Aborted multipart uploads count=0 kept=018812026/10/01 10:46:14 WARN Force mode enabled - objects will be deleted immediately without grace period18822026/10/01 10:46:14 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=018832026/10/01 10:46:14 INFO Vacuumed table table=pending_closures18842026/10/01 10:46:14 INFO Vacuumed table table=pending_objects18852026/10/01 10:46:14 INFO Vacuumed table table=multipart_uploads18862026/10/01 10:46:14 INFO Vacuumed table table=closures18872026/10/01 10:46:14 INFO Vacuumed table table=objects1888--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1889 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.25s)1890 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.37s)18912026/10/01 10:46:15 INFO Received uploads request method=POST path=/api/pending_closures1892--- PASS: TestConnectWaitsForAPeerMigration (8.32s)18932026/10/01 10:46:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18942026/10/01 10:46:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.493473764s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18952026/10/01 10:46:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1896--- PASS: TestPendingClosureWriteTimeout (0.00s)1897 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1898 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1899 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1900 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.21s)1901=== NAME TestPinProtectsFromGC1902 client_integration_test.go:840: Pin successfully protected closure from garbage collection1903--- PASS: TestPinProtectsFromGC (8.09s)19042026/10/01 10:46:17 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-config19052026/10/01 10:46:17 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.895008ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19062026/10/01 10:46:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.410689ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19072026/10/01 10:46:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.600558ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/10/01 10:46:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.608663207s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19092026/10/01 10:46:20 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"19102026/10/01 10:46:20 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-config19112026/10/01 10:46:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.199678ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19122026/10/01 10:46:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.486541ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19132026/10/01 10:46:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=816.098278ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19142026/10/01 10:46:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.575721123s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19152026/10/01 10:46:23 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_closures19162026/10/01 10:46:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.199279ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19172026/10/01 10:46:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.729115ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19182026/10/01 10:46:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=856.800369ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19192026/10/01 10:46:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.489811161s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1920--- PASS: TestClientErrorHandling (0.00s)1921 --- PASS: TestClientErrorHandling/InvalidStorePath (1.59s)1922 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.42s)1923 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.55s)1924PASS1925{"timestamp":"2026-10-01T10:46:26.42785Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:65054","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}19262026-10-01 10:46:26.563 UTC [69289] LOG: received smart shutdown request19272026-10-01 10:46:26.564 UTC [69289] LOG: background worker "logical replication launcher" (PID 69299) exited with exit code 119282026-10-01 10:46:26.570 UTC [69294] LOG: shutting down19292026-10-01 10:46:26.570 UTC [69294] LOG: checkpoint starting: shutdown immediate19302026-10-01 10:46:27.795 UTC [69294] LOG: checkpoint complete: wrote 12667 buffers (77.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.680 s, sync=0.507 s, total=1.225 s; sync files=29656, longest=0.001 s, average=0.001 s; distance=417145 kB, estimate=417145 kB; lsn=0/1AEEB3A0, redo lsn=0/1AEEB3A019312026-10-01 10:46:27.801 UTC [69289] LOG: database system is shut down1932Running OIDC tests...1933=== RUN TestAudienceForIssuer1934=== PAUSE TestAudienceForIssuer1935=== RUN TestGlobMatch1936=== PAUSE TestGlobMatch1937=== RUN TestValidateToken_ValidToken1938=== PAUSE TestValidateToken_ValidToken1939=== RUN TestValidateToken_WrongAudience1940=== PAUSE TestValidateToken_WrongAudience1941=== RUN TestValidateToken_Expired1942=== PAUSE TestValidateToken_Expired1943=== RUN TestValidateToken_BoundClaimsMismatch1944=== PAUSE TestValidateToken_BoundClaimsMismatch1945=== RUN TestValidateToken_BoundSubjectMismatch1946=== PAUSE TestValidateToken_BoundSubjectMismatch1947=== RUN TestValidateToken_MultipleProviders1948=== PAUSE TestValidateToken_MultipleProviders1949=== RUN TestValidateToken_NoMatchingProvider1950=== PAUSE TestValidateToken_NoMatchingProvider1951=== RUN TestValidateToken_KubernetesServiceAccount1952=== PAUSE TestValidateToken_KubernetesServiceAccount1953=== RUN TestNewValidator_KubernetesRequiresCA1954=== PAUSE TestNewValidator_KubernetesRequiresCA1955=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1956=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1957=== RUN TestPins_ReservedForMatchingRule1958=== PAUSE TestPins_ReservedForMatchingRule1959=== RUN TestPins_TopLevelShorthand1960=== PAUSE TestPins_TopLevelShorthand1961=== RUN TestPins_ConfigValidation1962=== PAUSE TestPins_ConfigValidation1963=== RUN TestScopes_LegacyProviderDefaultsToWrite1964=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1965=== RUN TestScopes_Rules1966=== PAUSE TestScopes_Rules1967=== RUN TestScopes_ConfigValidation1968=== PAUSE TestScopes_ConfigValidation1969=== CONT TestAudienceForIssuer1970--- PASS: TestAudienceForIssuer (0.00s)1971=== CONT TestValidateToken_NoMatchingProvider1972=== CONT TestPins_ConfigValidation1973=== CONT TestValidateToken_KubernetesServiceAccount1974=== CONT TestValidateToken_Expired1975=== CONT TestScopes_Rules1976=== CONT TestScopes_ConfigValidation1977=== CONT TestPins_ReservedForMatchingRule1978=== CONT TestValidateToken_BoundSubjectMismatch1979=== CONT TestValidateToken_MultipleProviders1980=== CONT TestScopes_LegacyProviderDefaultsToWrite1981--- PASS: TestPins_ConfigValidation (0.01s)1982=== CONT TestValidateToken_KubernetesIssuerFromOwnToken1983--- PASS: TestScopes_ConfigValidation (0.01s)1984=== CONT TestNewValidator_KubernetesRequiresCA19852026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65418/oidc1986--- PASS: TestValidateToken_Expired (0.03s)1987=== CONT TestValidateToken_WrongAudience19882026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65420/oidc1989--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)1990=== CONT TestValidateToken_ValidToken19912026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65423/oidc1992--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)1993=== CONT TestGlobMatch1994=== RUN TestGlobMatch/foo_foo1995=== PAUSE TestGlobMatch/foo_foo1996=== RUN TestGlobMatch/foo_bar1997=== PAUSE TestGlobMatch/foo_bar1998=== RUN TestGlobMatch/*_1999=== PAUSE TestGlobMatch/*_2000=== RUN TestGlobMatch/*_anything2001=== PAUSE TestGlobMatch/*_anything2002=== RUN TestGlobMatch/foo*_foo2003=== PAUSE TestGlobMatch/foo*_foo2004=== RUN TestGlobMatch/foo*_foobar2005=== PAUSE TestGlobMatch/foo*_foobar2006=== RUN TestGlobMatch/foo*_bar2007=== PAUSE TestGlobMatch/foo*_bar2008=== RUN TestGlobMatch/*bar_bar2009=== PAUSE TestGlobMatch/*bar_bar2010=== RUN TestGlobMatch/*bar_foobar2011=== PAUSE TestGlobMatch/*bar_foobar2012=== RUN TestGlobMatch/*bar_foo2013=== PAUSE TestGlobMatch/*bar_foo2014=== RUN TestGlobMatch/foo*bar_foobar2015=== PAUSE TestGlobMatch/foo*bar_foobar2016=== RUN TestGlobMatch/foo*bar_foo123bar2017=== PAUSE TestGlobMatch/foo*bar_foo123bar2018=== RUN TestGlobMatch/foo*bar_foobarbaz2019=== PAUSE TestGlobMatch/foo*bar_foobarbaz2020=== RUN TestGlobMatch/*/*_foo/bar2021=== PAUSE TestGlobMatch/*/*_foo/bar2022=== RUN TestGlobMatch/*/*_foo2023=== PAUSE TestGlobMatch/*/*_foo2024=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2025=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2026=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02027=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02028=== RUN TestGlobMatch/refs/*/main_refs/heads/main2029=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2030=== RUN TestGlobMatch/fo?_foo2031=== PAUSE TestGlobMatch/fo?_foo2032=== RUN TestGlobMatch/fo?_fo2033=== PAUSE TestGlobMatch/fo?_fo2034=== RUN TestGlobMatch/fo?_fooo2035=== PAUSE TestGlobMatch/fo?_fooo2036=== RUN TestGlobMatch/?oo_foo2037=== PAUSE TestGlobMatch/?oo_foo2038=== RUN TestGlobMatch/?oo_boo2039=== PAUSE TestGlobMatch/?oo_boo2040=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2041=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2042=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2043=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2044=== CONT TestPins_TopLevelShorthand20452026/10/01 10:46:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65422/oidc20462026/10/01 10:46:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:65426/oidc2047--- PASS: TestValidateToken_MultipleProviders (0.07s)2048=== CONT TestValidateToken_BoundClaimsMismatch20492026/10/01 10:46:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6542520502026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65430/oidc2051--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)2052=== CONT TestGlobMatch/foo_foo2053=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2054=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/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/*/*_foo/bar2065=== 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/*bar_bar2071=== CONT TestGlobMatch/foo*_bar2072=== CONT TestGlobMatch/foo*_foobar2073=== CONT TestGlobMatch/foo*_foo2074=== CONT TestGlobMatch/*_anything2075=== CONT TestGlobMatch/*_2076=== CONT TestGlobMatch/foo_bar2077--- PASS: TestGlobMatch (0.00s)2078 --- PASS: TestGlobMatch/foo_foo (0.00s)2079 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2080 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/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/*/*_foo/bar (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/*bar_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/foo_bar (0.00s)2103--- PASS: TestScopes_Rules (0.08s)21042026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65433/oidc2105--- PASS: TestPins_ReservedForMatchingRule (0.09s)21062026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65435/oidc2107--- PASS: TestValidateToken_WrongAudience (0.07s)21082026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65437/oidc2109--- PASS: TestValidateToken_ValidToken (0.07s)21102026/10/01 10:46:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321112026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65440/oidc2112--- PASS: TestPins_TopLevelShorthand (0.06s)2113--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)21142026/10/01 10:46:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65443/oidc2115--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)21162026/10/01 10:46:29 http: TLS handshake error from 127.0.0.1:65446: read tcp 127.0.0.1:65445->127.0.0.1:65446: use of closed network connection2117--- PASS: TestNewValidator_KubernetesRequiresCA (0.13s)21182026/10/01 10:46:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65432/oidc2119--- PASS: TestValidateToken_NoMatchingProvider (0.19s)2120PASS2121Running hook tests...2122=== RUN TestSendPathsEmpty2123=== PAUSE TestSendPathsEmpty2124=== RUN TestQueueEnqueueAndFetch2125=== PAUSE TestQueueEnqueueAndFetch2126=== RUN TestQueueDeduplication2127=== PAUSE TestQueueDeduplication2128=== RUN TestQueueRemove2129=== PAUSE TestQueueRemove2130=== RUN TestQueueFetchBatchLimit2131=== PAUSE TestQueueFetchBatchLimit2132=== RUN TestQueueRetryMovesToBack2133=== PAUSE TestQueueRetryMovesToBack2134=== RUN TestQueueFetchRemoveLifecycle2135=== PAUSE TestQueueFetchRemoveLifecycle2136=== RUN TestQueueConcurrentWriters2137=== PAUSE TestQueueConcurrentWriters2138=== RUN TestQueueRemoveLargeClosure2139=== PAUSE TestQueueRemoveLargeClosure2140=== RUN TestServerClientIntegration2141=== PAUSE TestServerClientIntegration2142=== RUN TestServerQueueError2143=== PAUSE TestServerQueueError2144=== RUN TestGetListenerSocketActivation2145 server_test.go:210: === RUN TestGetListenerSocketActivation2146 --- PASS: TestGetListenerSocketActivation (0.00s)2147 PASS2148 2149--- PASS: TestGetListenerSocketActivation (0.01s)2150=== RUN TestDrainIsolatesPoisonPath2151=== PAUSE TestDrainIsolatesPoisonPath2152=== RUN TestRunNotBlockedByPoisonHead2153=== PAUSE TestRunNotBlockedByPoisonHead2154=== RUN TestDrainGivesUpWhenServerDown2155=== PAUSE TestDrainGivesUpWhenServerDown2156=== RUN TestFailedPathPrunedByLaterClosure2157=== PAUSE TestFailedPathPrunedByLaterClosure2158=== RUN TestWorkerUploadsAndRemoves2159=== PAUSE TestWorkerUploadsAndRemoves2160=== RUN TestWorkerSkipsGCdPaths2161=== PAUSE TestWorkerSkipsGCdPaths2162=== RUN TestWorkerPrunesClosureDeps2163=== PAUSE TestWorkerPrunesClosureDeps2164=== RUN TestDrainTimeout2165=== PAUSE TestDrainTimeout2166=== CONT TestSendPathsEmpty2167=== CONT TestServerQueueError2168=== CONT TestWorkerUploadsAndRemoves2169--- PASS: TestSendPathsEmpty (0.00s)2170=== CONT TestServerClientIntegration2171=== CONT TestQueueRemoveLargeClosure2172=== CONT TestQueueConcurrentWriters2173=== CONT TestQueueFetchRemoveLifecycle2174=== CONT TestQueueRetryMovesToBack2175=== CONT TestQueueFetchBatchLimit2176=== CONT TestQueueRemove2177=== CONT TestQueueDeduplication21782026/10/01 10:46:29 ERROR Failed to queue paths error="permission denied" count=12179--- PASS: TestServerClientIntegration (0.00s)2180=== CONT TestQueueEnqueueAndFetch2181--- PASS: TestServerQueueError (0.00s)2182=== CONT TestWorkerPrunesClosureDeps2183--- PASS: TestQueueEnqueueAndFetch (0.01s)2184=== CONT TestDrainTimeout2185--- PASS: TestQueueDeduplication (0.01s)2186=== CONT TestWorkerSkipsGCdPaths21872026/10/01 10:46:29 INFO Upload queue status pending=221882026/10/01 10:46:29 INFO Upload queue status pending=221892026/10/01 10:46:29 INFO Uploading batch count=12190--- PASS: TestQueueFetchBatchLimit (0.01s)2191=== CONT TestDrainGivesUpWhenServerDown21922026/10/01 10:46:29 INFO Uploading batch count=22193--- PASS: TestQueueRemove (0.01s)2194=== CONT TestFailedPathPrunedByLaterClosure2195--- PASS: TestQueueRetryMovesToBack (0.01s)2196=== CONT TestRunNotBlockedByPoisonHead2197--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2198=== CONT TestDrainIsolatesPoisonPath21992026/10/01 10:46:29 INFO Uploading batch count=222002026/10/01 10:46:29 INFO Upload queue status pending=222012026/10/01 10:46:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-69215-2353416696/TestWorkerSkipsGCdPaths866380267/002/nonexistent22022026/10/01 10:46:29 INFO Uploading batch count=122032026/10/01 10:46:29 INFO Uploading batch count=122042026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=122052026/10/01 10:46:29 INFO Uploading batch count=422062026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=422072026/10/01 10:46:29 INFO Upload queue status pending=322082026/10/01 10:46:29 INFO Uploading batch count=122092026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=122102026/10/01 10:46:29 INFO Uploading batch count=122112026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainIsolatesPoisonPath3361723722/002/bbb22122026/10/01 10:46:29 INFO Uploading batch count=122132026/10/01 10:46:29 INFO Uploading batch count=222142026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=222152026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/a22162026/10/01 10:46:29 INFO Uploading batch count=122172026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=122182026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/b22192026/10/01 10:46:29 INFO Uploading batch count=122202026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=122212026/10/01 10:46:29 INFO Uploading batch count=122222026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=122232026/10/01 10:46:29 INFO Uploading batch count=222242026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=222252026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/c22262026/10/01 10:46:29 ERROR Drain finished with paths left in queue remaining=122272026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/d2228--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)22292026/10/01 10:46:29 INFO Uploading batch count=222302026/10/01 10:46:29 ERROR Upload failed error="upload failed" count=222312026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/e22322026/10/01 10:46:29 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69215-2353416696/TestDrainGivesUpWhenServerDown918357152/002/f22332026/10/01 10:46:29 ERROR Drain finished with paths left in queue remaining=102234--- PASS: TestDrainIsolatesPoisonPath (0.01s)2235--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2236--- PASS: TestWorkerUploadsAndRemoves (0.03s)2237--- PASS: TestWorkerPrunesClosureDeps (0.03s)2238--- PASS: TestWorkerSkipsGCdPaths (0.02s)2239--- PASS: TestQueueRemoveLargeClosure (0.05s)2240--- PASS: TestQueueConcurrentWriters (0.16s)22412026/10/01 10:46:29 ERROR Upload failed error="context deadline exceeded" count=222422026/10/01 10:46:29 ERROR Drain finished with paths left in queue remaining=42243--- PASS: TestDrainTimeout (0.21s)22442026/10/01 10:46:30 INFO Uploading batch count=122452026/10/01 10:46:30 INFO Uploading batch count=122462026/10/01 10:46:30 INFO Uploading batch count=122472026/10/01 10:46:30 ERROR Upload failed error="upload failed" count=122482026/10/01 10:46:30 INFO Uploading batch count=122492026/10/01 10:46:30 ERROR Upload failed error="upload failed" count=122502026/10/01 10:46:30 INFO Uploading batch count=122512026/10/01 10:46:30 ERROR Upload failed error="upload failed" count=122522026/10/01 10:46:30 INFO Uploading batch count=122532026/10/01 10:46:30 ERROR Upload failed error="upload failed" count=122542026/10/01 10:46:30 ERROR Drain finished with paths left in queue remaining=12255--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2256PASS