niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #227
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestPartSizeForNAR11=== PAUSE TestPartSizeForNAR12=== RUN TestUploadMultipart_SupersededByPeer13=== PAUSE TestUploadMultipart_SupersededByPeer14=== RUN TestDumpPathCaseHackMatchesNix15--- PASS: TestDumpPathCaseHackMatchesNix (0.21s)16=== RUN TestDumpPathCaseHackCollision17--- PASS: TestDumpPathCaseHackCollision (0.00s)18=== RUN TestDumpPathMatchesNix19=== PAUSE TestDumpPathMatchesNix20=== RUN TestDumpPathSingleFile21=== PAUSE TestDumpPathSingleFile22=== RUN TestDumpPathWriterError23=== PAUSE TestDumpPathWriterError24=== RUN TestEncodeNixBase3225=== PAUSE TestEncodeNixBase3226=== RUN TestEncodeNixBase32WithRealHash27=== PAUSE TestEncodeNixBase32WithRealHash28=== RUN TestConvertHashToNix3229=== PAUSE TestConvertHashToNix3230=== RUN TestGetStorePathHash31=== PAUSE TestGetStorePathHash32=== RUN TestPathInfoHashCompatibility33=== PAUSE TestPathInfoHashCompatibility34=== RUN TestParsePathInfoJSON35=== PAUSE TestParsePathInfoJSON36=== RUN TestParsePathInfoJSONMultiplePaths37=== PAUSE TestParsePathInfoJSONMultiplePaths38=== RUN TestPathInfoCACompatibility39=== PAUSE TestPathInfoCACompatibility40=== RUN TestRateLimiterFeedback41=== PAUSE TestRateLimiterFeedback42=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess44=== RUN TestResolveStorePath45=== PAUSE TestResolveStorePath46=== RUN TestDoWithRetry_BodyReplayedViaGetBody47=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody48=== RUN TestShellSplit49=== PAUSE TestShellSplit50=== RUN TestShellSplitErrors51=== PAUSE TestShellSplitErrors52=== RUN TestStreamPushReportsEveryPath53=== PAUSE TestStreamPushReportsEveryPath54=== RUN TestStreamPushBatchesUnderLoad55=== PAUSE TestStreamPushBatchesUnderLoad56=== RUN TestStreamPushIsolatesFailures57=== PAUSE TestStreamPushIsolatesFailures58=== RUN TestStreamPushGivesUpOnDeadServer59=== PAUSE TestStreamPushGivesUpOnDeadServer60=== RUN TestStreamPushRequestLine61=== PAUSE TestStreamPushRequestLine62=== RUN TestSetClientTLS63=== PAUSE TestSetClientTLS64=== RUN TestSetClientTLSDoesNotMutateDefaultTransport65=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport66=== RUN TestSetClientTLSErrors67=== PAUSE TestSetClientTLSErrors68=== RUN TestStaticToken69=== PAUSE TestStaticToken70=== RUN TestFileTokenReadsAndCaches71=== PAUSE TestFileTokenReadsAndCaches72=== RUN TestFileTokenMissing73=== PAUSE TestFileTokenMissing74=== RUN TestFileTokenEmpty75=== PAUSE TestFileTokenEmpty76=== RUN TestScriptTokenNoExpiryRerunsEveryCall77=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall78=== RUN TestScriptTokenCachesUntilRefresh79=== PAUSE TestScriptTokenCachesUntilRefresh80=== RUN TestScriptTokenEmptyToken81=== PAUSE TestScriptTokenEmptyToken82=== RUN TestScriptTokenBadJSON83=== PAUSE TestScriptTokenBadJSON84=== RUN TestScriptTokenScriptFails85=== PAUSE TestScriptTokenScriptFails86=== RUN TestScriptTokenEmptyCommand87=== PAUSE TestScriptTokenEmptyCommand88=== CONT TestDoServerRequestAttachesToken89=== CONT TestStreamPushRequestLine90=== CONT TestParsePathInfoJSON91=== RUN TestParsePathInfoJSON/Nix_format92=== PAUSE TestParsePathInfoJSON/Nix_format93=== RUN TestParsePathInfoJSON/Lix_format94=== PAUSE TestParsePathInfoJSON/Lix_format95=== CONT TestStreamPushGivesUpOnDeadServer96=== CONT TestStreamPushIsolatesFailures97=== CONT TestStreamPushBatchesUnderLoad98=== CONT TestStreamPushReportsEveryPath99=== CONT TestShellSplitErrors100--- PASS: TestShellSplitErrors (0.00s)101=== CONT TestResolveStorePath1022026/09/20 10:47:20 ERROR Upload failed error="bad path" count=31032026/09/20 10:47:20 ERROR Upload failed error="connection refused" count=201042026/09/20 10:47:20 ERROR Server seems unavailable, giving up on batch untried=17105=== CONT TestShellSplit106--- PASS: TestShellSplit (0.00s)107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== RUN TestParsePathInfoJSON/empty_input109=== PAUSE TestParsePathInfoJSON/empty_input110=== RUN TestParsePathInfoJSON/whitespace_only111=== PAUSE TestParsePathInfoJSON/whitespace_only112=== RUN TestParsePathInfoJSON/invalid_JSON113=== PAUSE TestParsePathInfoJSON/invalid_JSON114=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess115--- PASS: TestResolveStorePath (0.00s)116=== CONT TestPathInfoCACompatibility117=== RUN TestPathInfoCACompatibility/null_ca_field118=== PAUSE TestPathInfoCACompatibility/null_ca_field119=== RUN TestPathInfoCACompatibility/old_string_format_-_text120=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text121=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive122=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive123=== CONT TestRateLimiterFeedback124--- PASS: TestStreamPushIsolatesFailures (0.00s)125=== CONT TestParsePathInfoJSONMultiplePaths126=== RUN TestPathInfoCACompatibility/new_structured_format_-_text127--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)128=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text129=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths130=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method131=== RUN TestRateLimiterFeedback/429_enables_limiter132=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method133--- PASS: TestStreamPushReportsEveryPath (0.00s)134=== CONT TestDumpPathSingleFile1352026/09/20 10:47:20 ERROR Upload failed error=boom count=11362026/09/20 10:47:20 WARN Rate limiter enabled after throttle name=server-test rate=5137=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths139=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths140=== CONT TestConvertHashToNix32141=== RUN TestConvertHashToNix32/SRI_format_to_Nix32142=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32143=== RUN TestConvertHashToNix32/already_Nix32_format144=== CONT TestPathInfoHashCompatibility145=== PAUSE TestRateLimiterFeedback/429_enables_limiter146=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147=== RUN TestRateLimiterFeedback/503_enables_limiter148=== PAUSE TestRateLimiterFeedback/503_enables_limiter149=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter150=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter151=== PAUSE TestConvertHashToNix32/already_Nix32_format152=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== CONT TestGetStorePathHash154=== RUN TestGetStorePathHash/valid_store_path155=== PAUSE TestGetStorePathHash/valid_store_path156=== RUN TestGetStorePathHash/basename_without_hyphen_should_error157=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter158=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error159=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error160=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error161=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error162=== RUN TestConvertHashToNix32/invalid_format163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon165=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI166=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter167=== PAUSE TestConvertHashToNix32/invalid_format168=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error169=== CONT TestEncodeNixBase32WithRealHash170=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI171--- PASS: TestEncodeNixBase32WithRealHash (0.00s)172=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512174=== CONT TestFileTokenEmpty175=== CONT TestDumpPathWriterError176=== CONT TestEncodeNixBase32177=== CONT TestScriptTokenEmptyCommand178--- PASS: TestScriptTokenEmptyCommand (0.00s)179=== CONT TestScriptTokenScriptFails180=== RUN TestEncodeNixBase32/test_string_hash181=== PAUSE TestEncodeNixBase32/test_string_hash182=== RUN TestEncodeNixBase32/empty_input183=== PAUSE TestEncodeNixBase32/empty_input184=== CONT TestScriptTokenBadJSON185--- PASS: TestDoServerRequestAttachesToken (0.00s)186=== CONT TestScriptTokenEmptyToken1872026/09/20 10:47:20 WARN Rate limiter enabled after throttle name=server-test rate=51882026/09/20 10:47:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49187189--- PASS: TestFileTokenEmpty (0.00s)190=== CONT TestScriptTokenCachesUntilRefresh1912026/09/20 10:47:20 WARN Rate limiter backed off name=server-test rate=51922026/09/20 10:47:20 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49187193--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)194=== CONT TestScriptTokenNoExpiryRerunsEveryCall195--- PASS: TestScriptTokenScriptFails (0.01s)196=== CONT TestStaticToken197--- PASS: TestStaticToken (0.00s)198=== CONT TestFileTokenMissing199--- PASS: TestFileTokenMissing (0.00s)200=== CONT TestFileTokenReadsAndCaches201--- PASS: TestFileTokenReadsAndCaches (0.00s)202=== CONT TestPartSizeForNAR203=== RUN TestPartSizeForNAR/zero_stays_at_minimum204=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum205=== RUN TestPartSizeForNAR/small_stays_at_minimum206=== PAUSE TestPartSizeForNAR/small_stays_at_minimum207=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum208=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum209=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts210=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts211=== RUN TestPartSizeForNAR/1_TiB212=== PAUSE TestPartSizeForNAR/1_TiB213=== RUN TestPartSizeForNAR/5_TiB_S3_max_object214=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object215=== RUN TestPartSizeForNAR/capped_at_5_GiB216=== PAUSE TestPartSizeForNAR/capped_at_5_GiB217=== CONT TestDumpPathMatchesNix218--- PASS: TestScriptTokenBadJSON (0.01s)219=== CONT TestUploadMultipart_SupersededByPeer220=== RUN TestUploadMultipart_SupersededByPeer/exists221=== PAUSE TestUploadMultipart_SupersededByPeer/exists222=== RUN TestUploadMultipart_SupersededByPeer/missing223=== PAUSE TestUploadMultipart_SupersededByPeer/missing224=== CONT TestCaseHackSuffix225--- PASS: TestScriptTokenEmptyToken (0.01s)226=== CONT TestFilterOversizedClosures227=== RUN TestFilterOversizedClosures/no_limit_keeps_everything228=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything229=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== RUN TestFilterOversizedClosures/all_closures_skipped232=== PAUSE TestFilterOversizedClosures/all_closures_skipped233=== CONT TestRegisterUploadedObjectReusesConnections234--- PASS: TestStreamPushRequestLine (0.03s)235=== CONT TestSetClientTLSDoesNotMutateDefaultTransport236--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)237=== CONT TestSetClientTLSErrors238=== RUN TestSetClientTLSErrors/missing_cert_file239=== PAUSE TestSetClientTLSErrors/missing_cert_file240=== RUN TestSetClientTLSErrors/missing_key_file241=== PAUSE TestSetClientTLSErrors/missing_key_file242=== RUN TestSetClientTLSErrors/missing_ca_file243=== PAUSE TestSetClientTLSErrors/missing_ca_file244=== RUN TestSetClientTLSErrors/invalid_ca_file245=== PAUSE TestSetClientTLSErrors/invalid_ca_file246=== CONT TestSetClientTLS247=== RUN TestSetClientTLS/rejects_connection_without_client_cert248=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert249=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA250=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA251=== RUN TestSetClientTLS/preserves_debug_logging_transport252=== PAUSE TestSetClientTLS/preserves_debug_logging_transport253=== CONT TestParsePathInfoJSON/Nix_format254=== CONT TestParsePathInfoJSON/empty_input255=== CONT TestParsePathInfoJSON/Lix_format256=== CONT TestParsePathInfoJSON/whitespace_only257=== CONT TestParsePathInfoJSON/invalid_JSON258--- PASS: TestParsePathInfoJSON (0.00s)259 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)260 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)261 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)262 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)263 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)264=== CONT TestPathInfoCACompatibility/null_ca_field265=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method266=== CONT TestPathInfoCACompatibility/new_structured_format_-_text267=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive268=== CONT TestPathInfoCACompatibility/old_string_format_-_text269--- PASS: TestPathInfoCACompatibility (0.00s)270 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)271 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)272 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)273 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)274 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)275=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths276=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths277--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)278 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)279 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)280=== CONT TestRateLimiterFeedback/429_enables_limiter281--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)282=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter283=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2842026/09/20 10:47:20 WARN Rate limiter enabled after throttle name=server-test rate=52852026/09/20 10:47:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:492582862026/09/20 10:47:20 WARN Rate limiter backed off name=server-test rate=5287=== CONT TestRateLimiterFeedback/503_enables_limiter288=== CONT TestGetStorePathHash/valid_store_path289=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error290=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error291=== CONT TestGetStorePathHash/basename_without_hyphen_should_error292--- PASS: TestGetStorePathHash (0.00s)293 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)294 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)295 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)296 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)297=== CONT TestConvertHashToNix32/invalid_format298=== CONT TestConvertHashToNix32/already_Nix32_format299=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)300=== CONT TestConvertHashToNix32/SRI_format_to_Nix32301--- PASS: TestConvertHashToNix32 (0.00s)302 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)303 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)304 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)305=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512306=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI307=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon308--- PASS: TestPathInfoHashCompatibility (0.00s)309 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)310 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)313=== CONT TestEncodeNixBase32/test_string_hash314=== CONT TestEncodeNixBase32/empty_input315--- PASS: TestEncodeNixBase32 (0.00s)316 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)317 --- PASS: TestEncodeNixBase32/empty_input (0.00s)318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319=== CONT TestPartSizeForNAR/1_TiB320=== CONT TestPartSizeForNAR/capped_at_5_GiB321=== CONT TestPartSizeForNAR/5_TiB_S3_max_object322=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum323=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts324=== CONT TestPartSizeForNAR/small_stays_at_minimum325--- PASS: TestPartSizeForNAR (0.00s)326 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)328 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)329 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)330 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)331 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)332 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)333=== CONT TestUploadMultipart_SupersededByPeer/exists3342026/09/20 10:47:20 WARN Rate limiter enabled after throttle name=server-test rate=53352026/09/20 10:47:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:49264336--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)337=== CONT TestUploadMultipart_SupersededByPeer/missing338=== CONT TestFilterOversizedClosures/no_limit_keeps_everything339=== CONT TestFilterOversizedClosures/all_closures_skipped3402026/09/20 10:47:20 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=50341=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3422026/09/20 10:47:20 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=2000343--- PASS: TestFilterOversizedClosures (0.00s)344 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)345 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)346 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)347=== CONT TestSetClientTLSErrors/missing_cert_file3482026/09/20 10:47:20 WARN Rate limiter backed off name=server-test rate=5349--- PASS: TestRateLimiterFeedback (0.00s)350 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)351 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)352 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)354=== CONT TestSetClientTLSErrors/missing_ca_file355=== CONT TestSetClientTLSErrors/invalid_ca_file356--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)357 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)358 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)359=== CONT TestSetClientTLS/rejects_connection_without_client_cert360=== CONT TestSetClientTLS/preserves_debug_logging_transport361=== CONT TestSetClientTLSErrors/missing_key_file362--- PASS: TestSetClientTLSErrors (0.00s)363 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)365 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)367=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA368--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)3692026/09/20 10:47:20 http: TLS handshake error from 127.0.0.1:49270: remote error: tls: bad certificate370--- PASS: TestSetClientTLS (0.00s)371 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)372 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)373 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)374--- PASS: TestDumpPathWriterError (0.05s)375--- PASS: TestDumpPathSingleFile (0.06s)376--- PASS: TestCaseHackSuffix (0.05s)377--- PASS: TestDumpPathMatchesNix (0.08s)378--- PASS: TestStreamPushBatchesUnderLoad (0.10s)379--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)380PASS381Running server tests...382The files belonging to this database system will be owned by user "_nixbld1".383This user must also own the server process.384385The database cluster will be initialized with locale "C".386The default database encoding has accordingly been set to "SQL_ASCII".387The default text search configuration will be set to "english".388389Data page checksums are enabled.390391creating directory /nix/var/nix/builds/nix-5545-4069281544/postgres473330917/data ... ok392creating subdirectories ... ok393selecting dynamic shared memory implementation ... posix394selecting default "max_connections" ... 100395selecting default "shared_buffers" ... 128MB396selecting default time zone ... UTC397creating configuration files ... ok398running bootstrap script ... ok399performing post-bootstrap initialization ... ok400syncing data to disk ... ok401402initdb: warning: enabling "trust" authentication for local connections403initdb: 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.404405Success. You can now start the database server using:406407 pg_ctl -D /nix/var/nix/builds/nix-5545-4069281544/postgres473330917/data -l logfile start4084092026-09-20 10:47:22.042 UTC [5585] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4102026-09-20 10:47:22.042 UTC [5585] LOG: listening on Unix socket "/nix/var/nix/builds/nix-5545-4069281544/postgres473330917/.s.PGSQL.5432"4112026-09-20 10:47:22.044 UTC [5592] LOG: database system was shut down at 2026-09-20 10:47:22 UTC4122026-09-20 10:47:22.044 UTC [5593] FATAL: the database system is starting up413/nix/var/nix/builds/nix-5545-4069281544/postgres473330917:5432 - rejecting connections4142026-09-20 10:47:22.045 UTC [5585] LOG: database system is ready to accept connections415/nix/var/nix/builds/nix-5545-4069281544/postgres473330917:5432 - accepting connections416=== RUN TestService_AuthMiddleware417=== PAUSE TestService_AuthMiddleware418=== RUN TestService_AuthMiddleware_MTLSProxyHeader419=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader420=== RUN TestService_AuthMiddleware_MTLSBoundSubjects421=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects422=== RUN TestService_ReadAuthMiddleware423=== PAUSE TestService_ReadAuthMiddleware424=== RUN TestService_AuthMiddleware_OIDC425=== PAUSE TestService_AuthMiddleware_OIDC426=== RUN TestService_RequireScope_OIDC427=== PAUSE TestService_RequireScope_OIDC428=== RUN TestService_ReadScope_PublicByDefault429=== PAUSE TestService_ReadScope_PublicByDefault430=== RUN TestCacheConfigHandler431=== PAUSE TestCacheConfigHandler432=== RUN TestCacheStatsHandler433=== PAUSE TestCacheStatsHandler434=== RUN TestClientCADerivations435=== PAUSE TestClientCADerivations436=== RUN TestClientErrorHandling437=== PAUSE TestClientErrorHandling438=== RUN TestClientIntegration439=== PAUSE TestClientIntegration440=== RUN TestClientMultipleUploads441=== PAUSE TestClientMultipleUploads442=== RUN TestClientWithDependencies443=== PAUSE TestClientWithDependencies444=== RUN TestClientSharedPathCommittedMidPush445=== PAUSE TestClientSharedPathCommittedMidPush446=== RUN TestPinProtectsFromGC447=== PAUSE TestPinProtectsFromGC448=== RUN TestResolveDBConnectionString449=== PAUSE TestResolveDBConnectionString450=== RUN TestLeadElectsOneAndHandsOver451=== PAUSE TestLeadElectsOneAndHandsOver452=== RUN TestLeadEndsOnShutdown453=== PAUSE TestLeadEndsOnShutdown454=== RUN TestGCAdvisoryLockBlocksConcurrentRun4552026-09-20 10:47:22.479 UTC [5602] ERROR: relation "goose_db_version" does not exist at character 364562026-09-20 10:47:22.479 UTC [5602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4572026/09/20 10:47:22 OK 20241026095416_initial_model.sql (20.58ms)4582026/09/20 10:47:22 OK 20251210153512_drop_unused_gin_index.sql (925.96µs)4592026/09/20 10:47:22 OK 20251218171726_add_pins.sql (1.56ms)4602026/09/20 10:47:22 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)4612026/09/20 10:47:22 OK 20260905000000_add_claims.sql (1.76ms)4622026/09/20 10:47:22 OK 20260920000000_drop_claims.sql (1.28ms)4632026/09/20 10:47:22 goose: successfully migrated database to version: 202609200000004642026/09/20 10:47:22 OK 1_commit_pending_closure.sql (3.19ms)4652026/09/20 10:47:22 OK 2_object_stats_trigger.sql (292.96µs)4662026/09/20 10:47:22 goose: up to current file version: 2467--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.42s)468=== RUN TestGCBugBareHashReferences469=== PAUSE TestGCBugBareHashReferences470=== RUN TestGCMetrics471=== PAUSE TestGCMetrics472=== RUN TestGCTaskStore_StartNew473=== PAUSE TestGCTaskStore_StartNew474=== RUN TestGCTaskStore_DeduplicateSameParams475=== PAUSE TestGCTaskStore_DeduplicateSameParams476=== RUN TestGCTaskStore_ConflictDifferentParams477=== PAUSE TestGCTaskStore_ConflictDifferentParams478=== RUN TestGCTaskStore_GetEmpty479=== PAUSE TestGCTaskStore_GetEmpty480=== RUN TestGCTaskStore_GetReturnsLatest481=== PAUSE TestGCTaskStore_GetReturnsLatest482=== RUN TestGCTaskStore_CompletedAllowsNewTask483=== PAUSE TestGCTaskStore_CompletedAllowsNewTask484=== RUN TestGCTaskStore_PhaseUpdates485=== PAUSE TestGCTaskStore_PhaseUpdates486=== RUN TestGCTaskStore_Fail487=== PAUSE TestGCTaskStore_Fail488=== RUN TestGracefulShutdownDrainsInflight489=== PAUSE TestGracefulShutdownDrainsInflight490=== RUN TestService_healthCheckHandler491=== PAUSE TestService_healthCheckHandler492=== RUN TestService_readinessHandler493=== PAUSE TestService_readinessHandler494=== RUN TestGenerateLandingPage495=== PAUSE TestGenerateLandingPage496=== RUN TestCacheConfigHandlerMaxNarSize497=== PAUSE TestCacheConfigHandlerMaxNarSize498=== RUN TestCreatePendingClosureRejectsOversizedNAR499=== PAUSE TestCreatePendingClosureRejectsOversizedNAR500=== RUN TestNARDeduplicationMetadataUploadBug501=== PAUSE TestNARDeduplicationMetadataUploadBug502=== RUN TestMetricsInventory503=== PAUSE TestMetricsInventory504=== RUN TestService_NativeMTLS505=== PAUSE TestService_NativeMTLS506=== RUN TestServerTLSConfig507=== PAUSE TestServerTLSConfig508=== RUN TestMultipartCleanup509=== PAUSE TestMultipartCleanup510=== RUN TestObjectStatsTrigger511=== PAUSE TestObjectStatsTrigger512=== RUN TestOrphanedObjectsGC513=== PAUSE TestOrphanedObjectsGC514=== RUN TestOrphanedObjectsGCStressTest515=== PAUSE TestOrphanedObjectsGCStressTest516=== RUN TestResurrectedObjectNotDeleted517=== PAUSE TestResurrectedObjectNotDeleted518=== RUN TestParseSingleRange519=== PAUSE TestParseSingleRange520=== RUN TestIsValidCachePath521=== PAUSE TestIsValidCachePath522=== RUN TestReadProxyNarinfo523=== PAUSE TestReadProxyNarinfo524=== RUN TestReadProxyNarinfoAlreadyDecompressed525=== PAUSE TestReadProxyNarinfoAlreadyDecompressed526=== RUN TestReadProxyNarStreaming527=== PAUSE TestReadProxyNarStreaming528=== RUN TestReadProxy404529=== PAUSE TestReadProxy404530=== RUN TestReadProxyInvalidPath531=== PAUSE TestReadProxyInvalidPath532=== RUN TestReadProxyHead533=== PAUSE TestReadProxyHead534=== RUN TestReadProxyConditionalGet535=== PAUSE TestReadProxyConditionalGet536=== RUN TestReadProxyRootRedirectsToIndexHTML537=== PAUSE TestReadProxyRootRedirectsToIndexHTML538=== RUN TestReadProxyDisabled539=== PAUSE TestReadProxyDisabled540=== RUN TestReadRedirectNar541=== PAUSE TestReadRedirectNar542=== RUN TestReadRedirectKeepsNarinfoProxied543=== PAUSE TestReadRedirectKeepsNarinfoProxied544=== RUN TestReadProxyRangeRequest545=== PAUSE TestReadProxyRangeRequest546=== RUN TestReadRedirectUsesPublicS3URL547=== PAUSE TestReadRedirectUsesPublicS3URL548=== RUN TestRedundantMultipartUpload549=== PAUSE TestRedundantMultipartUpload550=== RUN TestCompleteMultipartUpload_ErrorButObjectExists551=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists552=== RUN TestCompletedNarNotReofferedAcrossClosures553=== PAUSE TestCompletedNarNotReofferedAcrossClosures554=== RUN TestPresignedUploadRegisteredBeforeCommit555=== PAUSE TestPresignedUploadRegisteredBeforeCommit556=== RUN TestService_Rustfstest557=== PAUSE TestService_Rustfstest558=== RUN TestParseSize559=== PAUSE TestParseSize560=== RUN TestSkippedUploadsHandler561=== PAUSE TestSkippedUploadsHandler562=== RUN TestSystemdListenerNotActivated563--- PASS: TestSystemdListenerNotActivated (0.00s)564=== RUN TestWatchdogBeatsWhenHealthy565--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)566=== RUN TestWatchdogSkipsWhenUnhealthy5672026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/20 10:47:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"577--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)578=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle579=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle580=== RUN TestProxyWriteTimeout581=== PAUSE TestProxyWriteTimeout582=== RUN TestIsValidUploadKey583=== PAUSE TestIsValidUploadKey584=== RUN TestUploadHandlersRejectInvalidKeys585=== PAUSE TestUploadHandlersRejectInvalidKeys586=== RUN TestUploadHandlersRejectOversizedBody587=== PAUSE TestUploadHandlersRejectOversizedBody588=== RUN TestService_cleanupPendingClosuresHandler589=== PAUSE TestService_cleanupPendingClosuresHandler590=== RUN TestService_createPendingClosureHandler591=== PAUSE TestService_createPendingClosureHandler592=== RUN TestService_verifyS3Integrity593=== PAUSE TestService_verifyS3Integrity594=== RUN TestCompleteMultipartUnregistered595=== PAUSE TestCompleteMultipartUnregistered596=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT597=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT598=== CONT TestServerTLSConfig599=== CONT TestService_AuthMiddleware600=== CONT TestGCBugBareHashReferences601=== RUN TestServerTLSConfig/no_client_CA602=== PAUSE TestServerTLSConfig/no_client_CA603=== RUN TestServerTLSConfig/missing_CA_file604=== PAUSE TestServerTLSConfig/missing_CA_file605=== RUN TestServerTLSConfig/not_a_PEM_file606=== PAUSE TestServerTLSConfig/not_a_PEM_file607=== CONT TestServerTLSConfig/no_client_CA608=== CONT TestGracefulShutdownDrainsInflight609=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT610=== CONT TestCompleteMultipartUnregistered611=== CONT TestService_verifyS3Integrity612=== CONT TestService_createPendingClosureHandler613=== CONT TestService_cleanupPendingClosuresHandler614=== CONT TestUploadHandlersRejectOversizedBody615=== CONT TestUploadHandlersRejectInvalidKeys6162026/09/20 10:47:22 INFO Starting HTTP server address=127.0.0.1:49284617=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info618=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info619=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal620=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal621=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key622=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key623=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key624=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key625=== CONT TestIsValidUploadKey626=== RUN TestIsValidUploadKey/narinfo6272026/09/20 10:47:22 INFO Shutdown signal received, draining in-flight requests timeout=10s628=== PAUSE TestIsValidUploadKey/narinfo629=== RUN TestIsValidUploadKey/nar_zst630=== PAUSE TestIsValidUploadKey/nar_zst631=== RUN TestIsValidUploadKey/nar_xz632=== PAUSE TestIsValidUploadKey/nar_xz633=== RUN TestIsValidUploadKey/nar_plain634=== PAUSE TestIsValidUploadKey/nar_plain635=== RUN TestIsValidUploadKey/listing636=== PAUSE TestIsValidUploadKey/listing637=== RUN TestIsValidUploadKey/build_log638=== PAUSE TestIsValidUploadKey/build_log639=== RUN TestIsValidUploadKey/build_log_home-manager_file640=== PAUSE TestIsValidUploadKey/build_log_home-manager_file641=== RUN TestIsValidUploadKey/build_log_plus_in_name642=== PAUSE TestIsValidUploadKey/build_log_plus_in_name643=== RUN TestIsValidUploadKey/build_log_question_mark644=== PAUSE TestIsValidUploadKey/build_log_question_mark645=== RUN TestIsValidUploadKey/build_log_equals646=== PAUSE TestIsValidUploadKey/build_log_equals647=== RUN TestIsValidUploadKey/realisation648=== PAUSE TestIsValidUploadKey/realisation649=== RUN TestIsValidUploadKey/realisation_plus_in_output650=== PAUSE TestIsValidUploadKey/realisation_plus_in_output651=== RUN TestIsValidUploadKey/nix-cache-info652=== PAUSE TestIsValidUploadKey/nix-cache-info653=== RUN TestIsValidUploadKey/index.html654=== PAUSE TestIsValidUploadKey/index.html655=== RUN TestIsValidUploadKey/narinfo_key,_nar_type656=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type657=== RUN TestIsValidUploadKey/nar_key,_narinfo_type658=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type659=== RUN TestIsValidUploadKey/listing_key,_narinfo_type660=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type661=== RUN TestIsValidUploadKey/traversal662=== PAUSE TestIsValidUploadKey/traversal663=== RUN TestIsValidUploadKey/traversal_nar664=== PAUSE TestIsValidUploadKey/traversal_nar665=== RUN TestIsValidUploadKey/absolute666=== PAUSE TestIsValidUploadKey/absolute667=== RUN TestIsValidUploadKey/empty_key668=== PAUSE TestIsValidUploadKey/empty_key669=== RUN TestIsValidUploadKey/unknown_type670=== PAUSE TestIsValidUploadKey/unknown_type671=== CONT TestProxyWriteTimeout672=== RUN TestProxyWriteTimeout/narinfo673=== PAUSE TestProxyWriteTimeout/narinfo674=== RUN TestProxyWriteTimeout/1_GiB_nar675=== PAUSE TestProxyWriteTimeout/1_GiB_nar676=== RUN TestProxyWriteTimeout/10_GiB_nar677=== PAUSE TestProxyWriteTimeout/10_GiB_nar678=== RUN TestProxyWriteTimeout/unknown_size679=== PAUSE TestProxyWriteTimeout/unknown_size680=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure682=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure683=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart684=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart685=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts686=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts687=== CONT TestSkippedUploadsHandler6882026/09/20 10:47:22 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000689--- PASS: TestSkippedUploadsHandler (0.00s)690=== CONT TestParseSize691--- PASS: TestParseSize (0.00s)692=== CONT TestService_Rustfstest693--- PASS: TestGracefulShutdownDrainsInflight (0.08s)694=== CONT TestPresignedUploadRegisteredBeforeCommit6952026-09-20 10:47:23.206 UTC [5688] ERROR: relation "goose_db_version" does not exist at character 366962026-09-20 10:47:23.206 UTC [5688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6972026-09-20 10:47:23.206 UTC [5687] ERROR: relation "goose_db_version" does not exist at character 366982026-09-20 10:47:23.206 UTC [5687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6992026-09-20 10:47:23.211 UTC [5689] ERROR: relation "goose_db_version" does not exist at character 367002026-09-20 10:47:23.211 UTC [5689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7012026-09-20 10:47:23.212 UTC [5691] ERROR: relation "goose_db_version" does not exist at character 367022026-09-20 10:47:23.212 UTC [5691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7032026-09-20 10:47:23.212 UTC [5690] ERROR: relation "goose_db_version" does not exist at character 367042026-09-20 10:47:23.212 UTC [5690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7052026-09-20 10:47:23.213 UTC [5695] ERROR: relation "goose_db_version" does not exist at character 367062026-09-20 10:47:23.213 UTC [5695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-09-20 10:47:23.213 UTC [5696] ERROR: relation "goose_db_version" does not exist at character 367082026-09-20 10:47:23.213 UTC [5696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-09-20 10:47:23.215 UTC [5693] ERROR: relation "goose_db_version" does not exist at character 367102026-09-20 10:47:23.215 UTC [5693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-09-20 10:47:23.215 UTC [5694] ERROR: relation "goose_db_version" does not exist at character 367122026-09-20 10:47:23.215 UTC [5694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-20 10:47:23.215 UTC [5692] ERROR: relation "goose_db_version" does not exist at character 367142026-09-20 10:47:23.215 UTC [5692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026/09/20 10:47:23 OK 20241026095416_initial_model.sql (7.4ms)7162026/09/20 10:47:23 OK 20241026095416_initial_model.sql (7.53ms)7172026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (738.88µs)7182026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (817.54µs)7192026/09/20 10:47:23 OK 20241026095416_initial_model.sql (5.35ms)7202026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (814.88µs)7212026/09/20 10:47:23 OK 20251218171726_add_pins.sql (2.44ms)7222026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.96ms)7232026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.77ms)7242026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (2.02ms)7252026/09/20 10:47:23 OK 20241026095416_initial_model.sql (6.85ms)7262026/09/20 10:47:23 OK 20241026095416_initial_model.sql (8.72ms)7272026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)7282026/09/20 10:47:23 OK 20241026095416_initial_model.sql (10.02ms)7292026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (738.88µs)7302026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (574.38µs)7312026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (637.33µs)7322026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)7332026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.77ms)7342026/09/20 10:47:23 OK 20241026095416_initial_model.sql (8.81ms)7352026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.56ms)7362026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.69ms)7372026/09/20 10:47:23 OK 20241026095416_initial_model.sql (7.92ms)7382026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (1ms)7392026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.29ms)7402026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007412026/09/20 10:47:23 OK 20260905000000_add_claims.sql (2.6ms)7422026/09/20 10:47:23 OK 20241026095416_initial_model.sql (7.47ms)7432026/09/20 10:47:23 OK 20241026095416_initial_model.sql (8.23ms)7442026/09/20 10:47:23 OK 20251218171726_add_pins.sql (2.12ms)7452026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (605.67µs)7462026/09/20 10:47:23 OK 20260905000000_add_claims.sql (2.33ms)7472026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)7482026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.13ms)7492026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (886.63µs)7502026/09/20 10:47:23 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)7512026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.57ms)7522026/09/20 10:47:23 OK 1_commit_pending_closure.sql (1.35ms)7532026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.52ms)7542026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007552026/09/20 10:47:23 OK 2_object_stats_trigger.sql (743.92µs)7562026/09/20 10:47:23 goose: up to current file version: 27572026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.69ms)7582026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.58ms)7592026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.57ms)7602026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007612026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.46ms)7622026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.7ms)7632026/09/20 10:47:23 OK 1_commit_pending_closure.sql (1.3ms)7642026/09/20 10:47:23 OK 20251218171726_add_pins.sql (1.91ms)7652026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)7662026/09/20 10:47:23 OK 20260905000000_add_claims.sql (2.42ms)7672026/09/20 10:47:23 OK 2_object_stats_trigger.sql (606.96µs)7682026/09/20 10:47:23 goose: up to current file version: 27692026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)7702026/09/20 10:47:23 OK 1_commit_pending_closure.sql (1.23ms)7712026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.38ms)7722026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007732026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.94ms)7742026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.28ms)7752026/09/20 10:47:23 OK 2_object_stats_trigger.sql (540.58µs)7762026/09/20 10:47:23 goose: up to current file version: 27772026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.02ms)7782026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007792026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.29ms)7802026/09/20 10:47:23 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)7812026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (717.71µs)7822026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007832026/09/20 10:47:23 OK 1_commit_pending_closure.sql (978.79µs)7842026/09/20 10:47:23 OK 1_commit_pending_closure.sql (993.33µs)7852026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.76ms)7862026/09/20 10:47:23 OK 2_object_stats_trigger.sql (322.79µs)7872026/09/20 10:47:23 goose: up to current file version: 27882026/09/20 10:47:23 OK 2_object_stats_trigger.sql (233.96µs)7892026/09/20 10:47:23 goose: up to current file version: 27902026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.51ms)7912026/09/20 10:47:23 OK 1_commit_pending_closure.sql (874.67µs)7922026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (1.32ms)7932026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007942026/09/20 10:47:23 OK 20260905000000_add_claims.sql (1.46ms)7952026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (711.96µs)7962026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000007972026/09/20 10:47:23 OK 2_object_stats_trigger.sql (411.13µs)7982026/09/20 10:47:23 goose: up to current file version: 27992026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (694.79µs)8002026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000008012026/09/20 10:47:23 OK 1_commit_pending_closure.sql (691µs)8022026/09/20 10:47:23 OK 20260920000000_drop_claims.sql (569.08µs)8032026/09/20 10:47:23 goose: successfully migrated database to version: 202609200000008042026/09/20 10:47:23 OK 1_commit_pending_closure.sql (658.21µs)8052026/09/20 10:47:23 OK 2_object_stats_trigger.sql (252.46µs)8062026/09/20 10:47:23 goose: up to current file version: 28072026/09/20 10:47:23 OK 2_object_stats_trigger.sql (179.25µs)8082026/09/20 10:47:23 goose: up to current file version: 28092026/09/20 10:47:23 OK 1_commit_pending_closure.sql (627.75µs)8102026/09/20 10:47:23 OK 2_object_stats_trigger.sql (162.38µs)8112026/09/20 10:47:23 goose: up to current file version: 28122026/09/20 10:47:23 OK 1_commit_pending_closure.sql (700.33µs)8132026/09/20 10:47:23 OK 2_object_stats_trigger.sql (165.83µs)8142026/09/20 10:47:23 goose: up to current file version: 28152026/09/20 10:47:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"816--- PASS: TestService_AuthMiddleware (0.40s)817=== CONT TestCompletedNarNotReofferedAcrossClosures8182026/09/20 10:47:23 INFO Received uploads request method=POST path=/api/pending_closures8192026/09/20 10:47:23 INFO Received uploads request method=POST path=/api/pending_closures8202026/09/20 10:47:23 INFO Received uploads request method=POST path=/api/pending_closures821--- PASS: TestService_Rustfstest (0.57s)822=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8232026/09/20 10:47:23 INFO Received cleanup request method=DELETE path=/api/pending_closures8242026/09/20 10:47:23 INFO Aborted multipart uploads count=08252026/09/20 10:47:23 INFO Received uploads request method=POST path=/api/pending_closures8262026/09/20 10:47:23 INFO Received cleanup request method=DELETE path=/api/pending_closures8272026/09/20 10:47:23 INFO Aborted multipart uploads count=18282026/09/20 10:47:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8292026-09-20 10:47:23.726 UTC [5689] ERROR: Closure does not exist: id=18302026-09-20 10:47:23.726 UTC [5689] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8312026-09-20 10:47:23.726 UTC [5689] STATEMENT: -- name: CommitPendingClosure :exec832 SELECT commit_pending_closure($1::bigint)833 834--- PASS: TestService_cleanupPendingClosuresHandler (0.81s)835=== CONT TestRedundantMultipartUpload8362026/09/20 10:47:23 INFO Received uploads request method=POST path=/api/pending_closures837--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.00s)838=== CONT TestReadRedirectUsesPublicS3URL8392026-09-20 10:47:23.929 UTC [5703] ERROR: relation "goose_db_version" does not exist at character 368402026-09-20 10:47:23.929 UTC [5703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026/09/20 10:47:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8422026/09/20 10:47:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst843--- PASS: TestCompleteMultipartUnregistered (1.08s)844=== CONT TestReadProxyRangeRequest8452026/09/20 10:47:24 OK 20241026095416_initial_model.sql (85.59ms)8462026/09/20 10:47:24 OK 20251210153512_drop_unused_gin_index.sql (8.17ms)8472026/09/20 10:47:24 OK 20251218171726_add_pins.sql (7.4ms)8482026/09/20 10:47:24 OK 20260628120000_add_object_size_and_stats.sql (29.99ms)8492026/09/20 10:47:24 OK 20260905000000_add_claims.sql (42.16ms)8502026/09/20 10:47:24 OK 20260920000000_drop_claims.sql (19.01ms)8512026/09/20 10:47:24 goose: successfully migrated database to version: 202609200000008522026/09/20 10:47:24 INFO Received uploads request method=POST path=/api/pending_closures8532026/09/20 10:47:24 OK 1_commit_pending_closure.sql (6.15ms)8542026/09/20 10:47:24 OK 2_object_stats_trigger.sql (1.73ms)8552026/09/20 10:47:24 goose: up to current file version: 28562026/09/20 10:47:24 INFO Received uploads request method=POST path=/api/pending_closures8572026/09/20 10:47:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8582026/09/20 10:47:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8592026-09-20 10:47:24.550 UTC [5708] ERROR: relation "goose_db_version" does not exist at character 368602026-09-20 10:47:24.550 UTC [5708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8612026/09/20 10:47:24 INFO Received uploads request method=POST path=/api/pending_closures8622026/09/20 10:47:24 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LjRlYmEzY2UwLTdjMjItNDllNS1iYzAwLWQyYzM0ZTdlY2RjMngxNzg5OTAxMjQzNDI1OTQwMDAw parts=108632026/09/20 10:47:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8642026/09/20 10:47:24 INFO Completed upload id=18652026/09/20 10:47:24 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008662026/09/20 10:47:24 INFO Received uploads request method=POST path=/api/pending_closures8672026/09/20 10:47:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures8682026/09/20 10:47:24 INFO Aborted multipart uploads count=08692026/09/20 10:47:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=08702026/09/20 10:47:24 INFO Vacuumed table table=pending_closures8712026/09/20 10:47:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8722026/09/20 10:47:24 INFO Received uploads request method=POST path=/api/pending_closures873--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.67s)874=== CONT TestReadRedirectKeepsNarinfoProxied8752026/09/20 10:47:24 INFO Vacuumed table table=pending_objects8762026/09/20 10:47:24 INFO Vacuumed table table=multipart_uploads8772026/09/20 10:47:24 INFO Vacuumed table table=closures8782026/09/20 10:47:24 INFO Vacuumed table table=objects8792026/09/20 10:47:24 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008802026/09/20 10:47:24 OK 20241026095416_initial_model.sql (108.51ms)881--- PASS: TestService_createPendingClosureHandler (1.80s)882=== CONT TestReadRedirectNar8832026/09/20 10:47:24 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8842026/09/20 10:47:24 OK 20251218171726_add_pins.sql (41.6ms)8852026-09-20 10:47:24.791 UTC [5712] ERROR: relation "goose_db_version" does not exist at character 368862026-09-20 10:47:24.791 UTC [5712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026/09/20 10:47:24 OK 20260628120000_add_object_size_and_stats.sql (22.99ms)8882026/09/20 10:47:24 OK 20260905000000_add_claims.sql (31.78ms)8892026-09-20 10:47:24.844 UTC [5715] ERROR: relation "goose_db_version" does not exist at character 368902026-09-20 10:47:24.844 UTC [5715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/09/20 10:47:24 OK 20260920000000_drop_claims.sql (30.04ms)8922026/09/20 10:47:24 goose: successfully migrated database to version: 202609200000008932026/09/20 10:47:24 OK 1_commit_pending_closure.sql (1.5ms)8942026/09/20 10:47:24 OK 2_object_stats_trigger.sql (349.17µs)8952026/09/20 10:47:24 goose: up to current file version: 28962026/09/20 10:47:24 OK 20241026095416_initial_model.sql (95.46ms)8972026/09/20 10:47:24 OK 20251210153512_drop_unused_gin_index.sql (4.35ms)8982026/09/20 10:47:24 OK 20251218171726_add_pins.sql (34.1ms)8992026/09/20 10:47:25 OK 20241026095416_initial_model.sql (117.72ms)9002026/09/20 10:47:25 OK 20260628120000_add_object_size_and_stats.sql (39.54ms)9012026/09/20 10:47:25 OK 20251210153512_drop_unused_gin_index.sql (7.08ms)9022026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9032026/09/20 10:47:25 OK 20251218171726_add_pins.sql (13.32ms)9042026/09/20 10:47:25 OK 20260905000000_add_claims.sql (35.52ms)9052026/09/20 10:47:25 OK 20260628120000_add_object_size_and_stats.sql (39.37ms)9062026/09/20 10:47:25 OK 20260920000000_drop_claims.sql (19.36ms)9072026/09/20 10:47:25 goose: successfully migrated database to version: 202609200000009082026/09/20 10:47:25 OK 1_commit_pending_closure.sql (3.26ms)9092026/09/20 10:47:25 OK 2_object_stats_trigger.sql (750.42µs)9102026/09/20 10:47:25 goose: up to current file version: 2911--- PASS: TestGCBugBareHashReferences (2.15s)912=== CONT TestReadProxyDisabled9132026/09/20 10:47:25 OK 20260905000000_add_claims.sql (69.56ms)9142026-09-20 10:47:25.147 UTC [5717] ERROR: relation "goose_db_version" does not exist at character 369152026-09-20 10:47:25.147 UTC [5717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026/09/20 10:47:25 OK 20260920000000_drop_claims.sql (45.87ms)9172026/09/20 10:47:25 goose: successfully migrated database to version: 202609200000009182026/09/20 10:47:25 OK 1_commit_pending_closure.sql (2.49ms)9192026/09/20 10:47:25 OK 2_object_stats_trigger.sql (516.79µs)9202026/09/20 10:47:25 goose: up to current file version: 29212026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9222026/09/20 10:47:25 OK 20241026095416_initial_model.sql (227.63ms)9232026/09/20 10:47:25 OK 20251210153512_drop_unused_gin_index.sql (10.4ms)9242026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9252026/09/20 10:47:25 OK 20251218171726_add_pins.sql (36.54ms)9262026/09/20 10:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9272026/09/20 10:47:25 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LmE1NjIzNTdjLWUyZmMtNGNkMS04ZmFjLTRlZjdmMjY5NGYyNHgxNzg5OTAxMjQ1MjU1NTgwMDAw9282026/09/20 10:47:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LmE1NjIzNTdjLWUyZmMtNGNkMS04ZmFjLTRlZjdmMjY5NGYyNHgxNzg5OTAxMjQ1MjU1NTgwMDAw parts=1929--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.97s)930=== CONT TestReadProxyRootRedirectsToIndexHTML9312026/09/20 10:47:25 OK 20260628120000_add_object_size_and_stats.sql (41.38ms)9322026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9332026/09/20 10:47:25 OK 20260905000000_add_claims.sql (59.52ms)9342026/09/20 10:47:25 OK 20260920000000_drop_claims.sql (21.48ms)9352026/09/20 10:47:25 goose: successfully migrated database to version: 202609200000009362026/09/20 10:47:25 OK 1_commit_pending_closure.sql (2ms)9372026/09/20 10:47:25 OK 2_object_stats_trigger.sql (361µs)9382026/09/20 10:47:25 goose: up to current file version: 29392026/09/20 10:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete940--- PASS: TestReadRedirectUsesPublicS3URL (1.82s)941=== CONT TestReadProxyConditionalGet9422026/09/20 10:47:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LjY5ZDJkYzljLTA4YjEtNDk5MS1hZmVlLTk5NTVjODVjODY1ZngxNzg5OTAxMjQ0MzkzMjY3MDAw parts=109432026/09/20 10:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026/09/20 10:47:25 INFO Completed upload id=19452026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/20 10:47:25 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/20 10:47:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9482026/09/20 10:47:25 WARN Found objects in DB but missing from S3, will re-upload count=1949--- PASS: TestService_verifyS3Integrity (2.88s)950=== CONT TestReadProxyHead951--- PASS: TestReadProxyRangeRequest (1.93s)952=== CONT TestReadProxyInvalidPath9532026-09-20 10:47:26.454 UTC [5727] ERROR: relation "goose_db_version" does not exist at character 369542026-09-20 10:47:26.454 UTC [5727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9552026-09-20 10:47:26.454 UTC [5728] ERROR: relation "goose_db_version" does not exist at character 369562026-09-20 10:47:26.454 UTC [5728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9572026/09/20 10:47:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9582026/09/20 10:47:26 OK 20241026095416_initial_model.sql (110.27ms)9592026/09/20 10:47:26 OK 20241026095416_initial_model.sql (111.66ms)9602026/09/20 10:47:26 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LmY4ZTdhOWVhLWVlY2MtNGE4MS1hZDA5LTk3MWExNjE1MjY0MngxNzg5OTAxMjQ1MDQ1ODk3MDAw parts=129612026/09/20 10:47:26 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)9622026/09/20 10:47:26 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)9632026/09/20 10:47:26 INFO Received uploads request method=POST path=/api/pending_closures964--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.28s)965=== CONT TestReadProxy4049662026/09/20 10:47:26 OK 20251218171726_add_pins.sql (4.71ms)9672026/09/20 10:47:26 OK 20251218171726_add_pins.sql (5.45ms)9682026/09/20 10:47:26 OK 20260628120000_add_object_size_and_stats.sql (17.17ms)9692026/09/20 10:47:26 OK 20260628120000_add_object_size_and_stats.sql (24.51ms)9702026/09/20 10:47:26 OK 20260905000000_add_claims.sql (30.87ms)9712026/09/20 10:47:26 OK 20260905000000_add_claims.sql (36.89ms)9722026/09/20 10:47:26 OK 20260920000000_drop_claims.sql (9.54ms)9732026/09/20 10:47:26 goose: successfully migrated database to version: 202609200000009742026/09/20 10:47:26 OK 20260920000000_drop_claims.sql (9.77ms)9752026/09/20 10:47:26 goose: successfully migrated database to version: 202609200000009762026/09/20 10:47:26 OK 1_commit_pending_closure.sql (1.87ms)9772026/09/20 10:47:26 OK 1_commit_pending_closure.sql (2.14ms)9782026/09/20 10:47:26 OK 2_object_stats_trigger.sql (410.5µs)9792026/09/20 10:47:26 goose: up to current file version: 29802026/09/20 10:47:26 OK 2_object_stats_trigger.sql (503.88µs)9812026/09/20 10:47:26 goose: up to current file version: 29822026-09-20 10:47:26.783 UTC [5731] ERROR: relation "goose_db_version" does not exist at character 369832026-09-20 10:47:26.783 UTC [5731] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC984--- PASS: TestReadRedirectNar (2.16s)985=== CONT TestReadProxyNarStreaming9862026/09/20 10:47:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9872026/09/20 10:47:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmEyNTQ3YWUtZmIyMC00NjdmLTllZjUtODZjZjkwMmRhNmM5LmMwMTA1MDA5LWJhMGUtNDZkNS04M2NmLWQ1ZWRlMTUyMGE4YXgxNzg5OTAxMjQ1NDc1NTU0MDAw parts=129882026/09/20 10:47:26 OK 20241026095416_initial_model.sql (151.17ms)989--- PASS: TestRedundantMultipartUpload (3.25s)990=== CONT TestReadProxyNarinfoAlreadyDecompressed9912026/09/20 10:47:26 OK 20251210153512_drop_unused_gin_index.sql (11.98ms)9922026/09/20 10:47:27 OK 20251218171726_add_pins.sql (47.79ms)9932026/09/20 10:47:27 OK 20260628120000_add_object_size_and_stats.sql (42.51ms)9942026/09/20 10:47:27 OK 20260905000000_add_claims.sql (8.1ms)9952026/09/20 10:47:27 OK 20260920000000_drop_claims.sql (2.63ms)9962026/09/20 10:47:27 goose: successfully migrated database to version: 202609200000009972026/09/20 10:47:27 OK 1_commit_pending_closure.sql (3.14ms)998=== CONT TestReadProxyNarinfo999--- PASS: TestReadRedirectKeepsNarinfoProxied (2.43s)10002026/09/20 10:47:27 OK 2_object_stats_trigger.sql (649µs)10012026/09/20 10:47:27 goose: up to current file version: 210022026-09-20 10:47:27.097 UTC [5736] ERROR: relation "goose_db_version" does not exist at character 3610032026-09-20 10:47:27.097 UTC [5736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10042026-09-20 10:47:27.218 UTC [5740] ERROR: relation "goose_db_version" does not exist at character 3610052026-09-20 10:47:27.218 UTC [5740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10062026-09-20 10:47:27.231 UTC [5739] ERROR: relation "goose_db_version" does not exist at character 3610072026-09-20 10:47:27.231 UTC [5739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/09/20 10:47:27 OK 20241026095416_initial_model.sql (95.1ms)10092026/09/20 10:47:27 OK 20251210153512_drop_unused_gin_index.sql (10.71ms)10102026/09/20 10:47:27 OK 20251218171726_add_pins.sql (35.89ms)1011--- PASS: TestReadProxyDisabled (2.23s)1012=== CONT TestIsValidCachePath1013=== RUN TestIsValidCachePath/narinfo1014=== PAUSE TestIsValidCachePath/narinfo1015=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1016=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1017=== RUN TestIsValidCachePath/nar_zst1018=== PAUSE TestIsValidCachePath/nar_zst1019=== RUN TestIsValidCachePath/nar_xz1020=== PAUSE TestIsValidCachePath/nar_xz1021=== RUN TestIsValidCachePath/nar_bz21022=== PAUSE TestIsValidCachePath/nar_bz21023=== RUN TestIsValidCachePath/nar_uncompressed1024=== PAUSE TestIsValidCachePath/nar_uncompressed1025=== RUN TestIsValidCachePath/ls1026=== PAUSE TestIsValidCachePath/ls1027=== RUN TestIsValidCachePath/log1028=== PAUSE TestIsValidCachePath/log1029=== RUN TestIsValidCachePath/realisation1030=== PAUSE TestIsValidCachePath/realisation1031=== RUN TestIsValidCachePath/nix-cache-info1032=== PAUSE TestIsValidCachePath/nix-cache-info1033=== RUN TestIsValidCachePath/index.html1034=== PAUSE TestIsValidCachePath/index.html1035=== RUN TestIsValidCachePath/traversal_parent1036=== PAUSE TestIsValidCachePath/traversal_parent1037=== RUN TestIsValidCachePath/traversal_in_middle1038=== PAUSE TestIsValidCachePath/traversal_in_middle1039=== RUN TestIsValidCachePath/invalid_char_e1040=== PAUSE TestIsValidCachePath/invalid_char_e1041=== RUN TestIsValidCachePath/invalid_char_u1042=== PAUSE TestIsValidCachePath/invalid_char_u1043=== RUN TestIsValidCachePath/random_path1044=== PAUSE TestIsValidCachePath/random_path1045=== RUN TestIsValidCachePath/empty1046=== PAUSE TestIsValidCachePath/empty1047=== RUN TestIsValidCachePath/leading_slash1048=== PAUSE TestIsValidCachePath/leading_slash1049=== RUN TestIsValidCachePath/wrong_extension1050=== PAUSE TestIsValidCachePath/wrong_extension1051=== RUN TestIsValidCachePath/short_hash1052=== PAUSE TestIsValidCachePath/short_hash1053=== CONT TestParseSingleRange1054=== RUN TestParseSingleRange/none1055=== PAUSE TestParseSingleRange/none1056=== RUN TestParseSingleRange/unknown_unit1057=== PAUSE TestParseSingleRange/unknown_unit1058=== RUN TestParseSingleRange/multi-range_ignored1059=== PAUSE TestParseSingleRange/multi-range_ignored1060=== RUN TestParseSingleRange/malformed_no_dash1061=== PAUSE TestParseSingleRange/malformed_no_dash1062=== RUN TestParseSingleRange/malformed_both_empty1063=== PAUSE TestParseSingleRange/malformed_both_empty1064=== RUN TestParseSingleRange/malformed_end_before_start1065=== PAUSE TestParseSingleRange/malformed_end_before_start1066=== RUN TestParseSingleRange/closed1067=== PAUSE TestParseSingleRange/closed1068=== RUN TestParseSingleRange/open-ended1069=== PAUSE TestParseSingleRange/open-ended1070=== RUN TestParseSingleRange/end_clamped_to_size1071=== PAUSE TestParseSingleRange/end_clamped_to_size1072=== RUN TestParseSingleRange/suffix1073=== PAUSE TestParseSingleRange/suffix1074=== RUN TestParseSingleRange/suffix_exceeds_size1075=== PAUSE TestParseSingleRange/suffix_exceeds_size1076=== RUN TestParseSingleRange/single_byte1077=== PAUSE TestParseSingleRange/single_byte1078=== RUN TestParseSingleRange/start_past_EOF1079=== PAUSE TestParseSingleRange/start_past_EOF1080=== RUN TestParseSingleRange/start_far_past_EOF1081=== PAUSE TestParseSingleRange/start_far_past_EOF1082=== CONT TestResurrectedObjectNotDeleted10832026/09/20 10:47:27 OK 20260628120000_add_object_size_and_stats.sql (14.46ms)10842026-09-20 10:47:27.316 UTC [5741] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-20 10:47:27.316 UTC [5741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/09/20 10:47:27 OK 20241026095416_initial_model.sql (54.94ms)10872026/09/20 10:47:27 OK 20260905000000_add_claims.sql (6.96ms)10882026/09/20 10:47:27 OK 20241026095416_initial_model.sql (39.23ms)10892026/09/20 10:47:27 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)10902026/09/20 10:47:27 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)10912026/09/20 10:47:27 OK 20260920000000_drop_claims.sql (1.83ms)10922026/09/20 10:47:27 goose: successfully migrated database to version: 2026092000000010932026/09/20 10:47:27 OK 1_commit_pending_closure.sql (2.22ms)10942026/09/20 10:47:27 OK 2_object_stats_trigger.sql (517.38µs)10952026/09/20 10:47:27 goose: up to current file version: 210962026/09/20 10:47:27 OK 20251218171726_add_pins.sql (3.52ms)10972026/09/20 10:47:27 OK 20251218171726_add_pins.sql (5.55ms)10982026/09/20 10:47:27 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)10992026/09/20 10:47:27 OK 20260628120000_add_object_size_and_stats.sql (17.93ms)11002026/09/20 10:47:27 OK 20260905000000_add_claims.sql (26.75ms)11012026/09/20 10:47:27 OK 20260920000000_drop_claims.sql (17.47ms)11022026/09/20 10:47:27 goose: successfully migrated database to version: 2026092000000011032026/09/20 10:47:27 OK 20260905000000_add_claims.sql (30.46ms)11042026/09/20 10:47:27 OK 1_commit_pending_closure.sql (3.27ms)11052026/09/20 10:47:27 OK 2_object_stats_trigger.sql (1.03ms)11062026/09/20 10:47:27 goose: up to current file version: 211072026/09/20 10:47:27 OK 20260920000000_drop_claims.sql (16.37ms)11082026/09/20 10:47:27 goose: successfully migrated database to version: 2026092000000011092026/09/20 10:47:27 OK 1_commit_pending_closure.sql (2.8ms)11102026/09/20 10:47:27 OK 2_object_stats_trigger.sql (433.25µs)11112026/09/20 10:47:27 goose: up to current file version: 211122026/09/20 10:47:27 OK 20241026095416_initial_model.sql (66.88ms)11132026/09/20 10:47:27 OK 20251210153512_drop_unused_gin_index.sql (13.73ms)11142026/09/20 10:47:27 OK 20251218171726_add_pins.sql (13.29ms)11152026/09/20 10:47:27 OK 20260628120000_add_object_size_and_stats.sql (28.24ms)11162026/09/20 10:47:27 OK 20260905000000_add_claims.sql (7.19ms)1117--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.97s)1118=== CONT TestOrphanedObjectsGCStressTest11192026/09/20 10:47:27 OK 20260920000000_drop_claims.sql (15.93ms)11202026/09/20 10:47:27 goose: successfully migrated database to version: 2026092000000011212026/09/20 10:47:27 OK 1_commit_pending_closure.sql (2.25ms)11222026/09/20 10:47:27 OK 2_object_stats_trigger.sql (556.54µs)11232026/09/20 10:47:27 goose: up to current file version: 21124--- PASS: TestReadProxyHead (1.81s)1125=== CONT TestOrphanedObjectsGC1126--- PASS: TestReadProxyConditionalGet (2.07s)1127=== CONT TestObjectStatsTrigger11282026-09-20 10:47:28.023 UTC [5750] ERROR: relation "goose_db_version" does not exist at character 3611292026-09-20 10:47:28.023 UTC [5750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1130--- PASS: TestReadProxyInvalidPath (2.14s)1131=== CONT TestMultipartCleanup11322026-09-20 10:47:28.152 UTC [5753] ERROR: relation "goose_db_version" does not exist at character 3611332026-09-20 10:47:28.152 UTC [5753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/09/20 10:47:28 OK 20241026095416_initial_model.sql (60.42ms)11352026/09/20 10:47:28 OK 20251210153512_drop_unused_gin_index.sql (23.67ms)11362026/09/20 10:47:28 OK 20251218171726_add_pins.sql (14.3ms)11372026-09-20 10:47:28.216 UTC [5754] ERROR: relation "goose_db_version" does not exist at character 3611382026-09-20 10:47:28.216 UTC [5754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11392026/09/20 10:47:28 OK 20260628120000_add_object_size_and_stats.sql (31.52ms)11402026/09/20 10:47:28 OK 20260905000000_add_claims.sql (16.54ms)11412026/09/20 10:47:28 OK 20260920000000_drop_claims.sql (10.31ms)11422026/09/20 10:47:28 goose: successfully migrated database to version: 2026092000000011432026/09/20 10:47:28 OK 1_commit_pending_closure.sql (2.75ms)11442026/09/20 10:47:28 OK 2_object_stats_trigger.sql (582.71µs)11452026/09/20 10:47:28 goose: up to current file version: 211462026/09/20 10:47:28 OK 20241026095416_initial_model.sql (113.84ms)11472026/09/20 10:47:28 OK 20251210153512_drop_unused_gin_index.sql (9.81ms)11482026/09/20 10:47:28 OK 20251218171726_add_pins.sql (38.49ms)11492026/09/20 10:47:28 OK 20260628120000_add_object_size_and_stats.sql (20.82ms)11502026-09-20 10:47:28.399 UTC [5755] ERROR: relation "goose_db_version" does not exist at character 3611512026-09-20 10:47:28.399 UTC [5755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026/09/20 10:47:28 OK 20241026095416_initial_model.sql (156.77ms)11532026/09/20 10:47:28 OK 20260905000000_add_claims.sql (13.16ms)11542026/09/20 10:47:28 OK 20251210153512_drop_unused_gin_index.sql (10.64ms)11552026/09/20 10:47:28 OK 20260920000000_drop_claims.sql (18.53ms)11562026/09/20 10:47:28 goose: successfully migrated database to version: 2026092000000011572026/09/20 10:47:28 OK 1_commit_pending_closure.sql (67.39ms)11582026/09/20 10:47:28 OK 2_object_stats_trigger.sql (1.37ms)11592026/09/20 10:47:28 goose: up to current file version: 211602026/09/20 10:47:28 OK 20251218171726_add_pins.sql (82.53ms)1161--- PASS: TestReadProxy404 (1.94s)1162=== CONT TestServerTLSConfig/not_a_PEM_file11632026/09/20 10:47:28 OK 20260628120000_add_object_size_and_stats.sql (44.5ms)1164=== CONT TestServerTLSConfig/missing_CA_file1165--- PASS: TestServerTLSConfig (0.00s)1166 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1167 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1168 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1169=== CONT TestPinProtectsFromGC11702026/09/20 10:47:28 OK 20260905000000_add_claims.sql (48.15ms)11712026/09/20 10:47:28 OK 20260920000000_drop_claims.sql (49.72ms)11722026/09/20 10:47:28 goose: successfully migrated database to version: 2026092000000011732026/09/20 10:47:28 OK 1_commit_pending_closure.sql (3.62ms)11742026/09/20 10:47:28 OK 2_object_stats_trigger.sql (840.96µs)11752026/09/20 10:47:28 goose: up to current file version: 211762026/09/20 10:47:28 OK 20241026095416_initial_model.sql (252.66ms)11772026/09/20 10:47:28 OK 20251210153512_drop_unused_gin_index.sql (12.37ms)11782026/09/20 10:47:28 OK 20251218171726_add_pins.sql (29.3ms)11792026/09/20 10:47:28 OK 20260628120000_add_object_size_and_stats.sql (59.35ms)1180--- PASS: TestReadProxyNarStreaming (2.00s)1181=== CONT TestLeadEndsOnShutdown11822026/09/20 10:47:28 OK 20260905000000_add_claims.sql (91.74ms)11832026/09/20 10:47:28 OK 20260920000000_drop_claims.sql (46.67ms)11842026/09/20 10:47:28 goose: successfully migrated database to version: 2026092000000011852026/09/20 10:47:28 OK 1_commit_pending_closure.sql (2.93ms)11862026/09/20 10:47:28 OK 2_object_stats_trigger.sql (652.29µs)11872026/09/20 10:47:28 goose: up to current file version: 211882026-09-20 10:47:29.078 UTC [5760] ERROR: relation "goose_db_version" does not exist at character 3611892026-09-20 10:47:29.078 UTC [5760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1190--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.16s)1191=== CONT TestLeadElectsOneAndHandsOver11922026/09/20 10:47:29 OK 20241026095416_initial_model.sql (167.71ms)11932026/09/20 10:47:29 OK 20251210153512_drop_unused_gin_index.sql (9.07ms)11942026-09-20 10:47:29.359 UTC [5763] ERROR: relation "goose_db_version" does not exist at character 3611952026-09-20 10:47:29.359 UTC [5763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11962026/09/20 10:47:29 OK 20251218171726_add_pins.sql (42.33ms)11972026/09/20 10:47:29 OK 20260628120000_add_object_size_and_stats.sql (45.99ms)1198--- PASS: TestReadProxyNarinfo (2.33s)1199=== CONT TestResolveDBConnectionString1200=== RUN TestResolveDBConnectionString/flag_wins1201=== PAUSE TestResolveDBConnectionString/flag_wins1202=== RUN TestResolveDBConnectionString/file_when_flag_empty1203=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1204=== RUN TestResolveDBConnectionString/missing_file_is_an_error1205=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1206=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1207=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1208=== RUN TestResolveDBConnectionString/nothing_configured1209=== PAUSE TestResolveDBConnectionString/nothing_configured1210=== CONT TestCreatePendingClosureRejectsOversizedNAR12112026/09/20 10:47:29 INFO Received uploads request method=POST path=/api/pending_closures1212--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1213=== CONT TestService_NativeMTLS12142026/09/20 10:47:29 OK 20260905000000_add_claims.sql (61.28ms)12152026/09/20 10:47:29 OK 20260920000000_drop_claims.sql (8.24ms)12162026/09/20 10:47:29 goose: successfully migrated database to version: 2026092000000012172026/09/20 10:47:29 OK 1_commit_pending_closure.sql (3.65ms)12182026/09/20 10:47:29 OK 2_object_stats_trigger.sql (1.05ms)12192026/09/20 10:47:29 goose: up to current file version: 212202026-09-20 10:47:29.512 UTC [5766] ERROR: relation "goose_db_version" does not exist at character 3612212026-09-20 10:47:29.512 UTC [5766] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/09/20 10:47:29 OK 20241026095416_initial_model.sql (102.33ms)12232026/09/20 10:47:29 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)12242026/09/20 10:47:29 WARN Rate limiter enabled after throttle name=s3-test rate=512252026/09/20 10:47:29 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1226=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1227 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101228 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001229--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.60s)1230=== CONT TestMetricsInventory12312026/09/20 10:47:29 OK 20251218171726_add_pins.sql (9.31ms)12322026/09/20 10:47:29 OK 20260628120000_add_object_size_and_stats.sql (28.44ms)12332026-09-20 10:47:29.600 UTC [5767] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-20 10:47:29.600 UTC [5767] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/20 10:47:29 OK 20260905000000_add_claims.sql (64.41ms)12362026/09/20 10:47:29 OK 20260920000000_drop_claims.sql (26.89ms)12372026/09/20 10:47:29 goose: successfully migrated database to version: 2026092000000012382026/09/20 10:47:29 OK 1_commit_pending_closure.sql (2.99ms)12392026/09/20 10:47:29 OK 2_object_stats_trigger.sql (715.38µs)12402026/09/20 10:47:29 goose: up to current file version: 212412026/09/20 10:47:29 OK 20241026095416_initial_model.sql (155.72ms)12422026/09/20 10:47:29 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)12432026/09/20 10:47:29 OK 20251218171726_add_pins.sql (90.67ms)12442026/09/20 10:47:29 OK 20241026095416_initial_model.sql (175.86ms)12452026/09/20 10:47:29 OK 20260628120000_add_object_size_and_stats.sql (49.57ms)12462026/09/20 10:47:29 OK 20251210153512_drop_unused_gin_index.sql (16.77ms)12472026/09/20 10:47:29 OK 20251218171726_add_pins.sql (8.56ms)12482026/09/20 10:47:29 OK 20260905000000_add_claims.sql (22.2ms)12492026/09/20 10:47:29 OK 20260628120000_add_object_size_and_stats.sql (49.58ms)1250--- PASS: TestResurrectedObjectNotDeleted (2.60s)1251=== CONT TestNARDeduplicationMetadataUploadBug12522026/09/20 10:47:29 OK 20260920000000_drop_claims.sql (61.1ms)12532026/09/20 10:47:29 goose: successfully migrated database to version: 2026092000000012542026/09/20 10:47:29 OK 1_commit_pending_closure.sql (2.65ms)12552026/09/20 10:47:29 OK 2_object_stats_trigger.sql (581µs)12562026/09/20 10:47:29 goose: up to current file version: 212572026/09/20 10:47:29 OK 20260905000000_add_claims.sql (87.36ms)12582026/09/20 10:47:30 OK 20260920000000_drop_claims.sql (47.88ms)12592026/09/20 10:47:30 goose: successfully migrated database to version: 2026092000000012602026/09/20 10:47:30 OK 1_commit_pending_closure.sql (8.36ms)12612026/09/20 10:47:30 OK 2_object_stats_trigger.sql (2.1ms)12622026/09/20 10:47:30 goose: up to current file version: 212632026-09-20 10:47:30.093 UTC [5772] ERROR: relation "goose_db_version" does not exist at character 3612642026-09-20 10:47:30.093 UTC [5772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12652026/09/20 10:47:30 OK 20241026095416_initial_model.sql (236.14ms)12662026/09/20 10:47:30 OK 20251210153512_drop_unused_gin_index.sql (13.23ms)12672026/09/20 10:47:30 OK 20251218171726_add_pins.sql (31.59ms)12682026/09/20 10:47:30 OK 20260628120000_add_object_size_and_stats.sql (50.4ms)12692026/09/20 10:47:30 OK 20260905000000_add_claims.sql (88.87ms)12702026/09/20 10:47:30 OK 20260920000000_drop_claims.sql (25.01ms)12712026/09/20 10:47:30 goose: successfully migrated database to version: 2026092000000012722026/09/20 10:47:30 OK 1_commit_pending_closure.sql (4.25ms)1273--- PASS: TestObjectStatsTrigger (2.83s)1274=== CONT TestClientWithDependencies12752026/09/20 10:47:30 OK 2_object_stats_trigger.sql (1.07ms)12762026/09/20 10:47:30 goose: up to current file version: 212772026-09-20 10:47:30.777 UTC [5775] ERROR: relation "goose_db_version" does not exist at character 3612782026-09-20 10:47:30.777 UTC [5775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/09/20 10:47:30 INFO Received uploads request method=POST path=/api/pending_closures12802026-09-20 10:47:30.988 UTC [5776] ERROR: relation "goose_db_version" does not exist at character 3612812026-09-20 10:47:30.988 UTC [5776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12822026/09/20 10:47:31 OK 20241026095416_initial_model.sql (194.75ms)12832026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (3.7ms)12842026/09/20 10:47:31 OK 20251218171726_add_pins.sql (22.6ms)12852026-09-20 10:47:31.082 UTC [5777] ERROR: relation "goose_db_version" does not exist at character 3612862026-09-20 10:47:31.082 UTC [5777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12872026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (25.15ms)12882026/09/20 10:47:31 INFO Received cleanup request method=DELETE path=/api/pending_closures12892026/09/20 10:47:31 INFO Aborted multipart uploads count=112902026/09/20 10:47:31 OK 20260905000000_add_claims.sql (40.02ms)12912026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (10.5ms)12922026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000012932026/09/20 10:47:31 OK 20241026095416_initial_model.sql (103.37ms)12942026/09/20 10:47:31 OK 1_commit_pending_closure.sql (5.61ms)1295--- PASS: TestMultipartCleanup (3.09s)1296=== CONT TestClientSharedPathCommittedMidPush12972026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)12982026/09/20 10:47:31 OK 2_object_stats_trigger.sql (3.59ms)12992026/09/20 10:47:31 goose: up to current file version: 213002026/09/20 10:47:31 OK 20251218171726_add_pins.sql (6.47ms)1301=== NAME TestOrphanedObjectsGC1302 orphaned_objects_gc_test.go:290: GC Test Summary:1303 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1304 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1305 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1306 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1307 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1308--- PASS: TestOrphanedObjectsGC (3.56s)1309=== CONT TestGenerateLandingPage1310--- PASS: TestGenerateLandingPage (0.00s)1311=== CONT TestCacheConfigHandlerMaxNarSize1312--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1313=== CONT TestGCTaskStore_GetEmpty1314--- PASS: TestGCTaskStore_GetEmpty (0.00s)1315=== CONT TestGCTaskStore_Fail1316--- PASS: TestGCTaskStore_Fail (0.00s)1317=== CONT TestGCTaskStore_PhaseUpdates1318--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1319=== CONT TestGCTaskStore_CompletedAllowsNewTask1320--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1321=== CONT TestGCTaskStore_GetReturnsLatest1322--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1323=== CONT TestService_RequireScope_OIDC13242026/09/20 10:47:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49365/oidc13252026/09/20 10:47:31 OK 20241026095416_initial_model.sql (67.81ms)13262026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)13272026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (36.64ms)13282026/09/20 10:47:31 OK 20251218171726_add_pins.sql (12.12ms)13292026-09-20 10:47:31.231 UTC [5781] ERROR: relation "goose_db_version" does not exist at character 3613302026-09-20 10:47:31.231 UTC [5781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13312026/09/20 10:47:31 OK 20260905000000_add_claims.sql (34.26ms)13322026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (30.91ms)13332026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (3.23ms)13342026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000013352026/09/20 10:47:31 OK 1_commit_pending_closure.sql (1.84ms)13362026/09/20 10:47:31 OK 2_object_stats_trigger.sql (365.21µs)13372026/09/20 10:47:31 goose: up to current file version: 213382026-09-20 10:47:31.271 UTC [5783] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-20 10:47:31.271 UTC [5783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026/09/20 10:47:31 OK 20260905000000_add_claims.sql (27.93ms)13412026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (17.52ms)13422026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000013432026/09/20 10:47:31 OK 1_commit_pending_closure.sql (2.49ms)13442026/09/20 10:47:31 OK 2_object_stats_trigger.sql (715.96µs)13452026/09/20 10:47:31 goose: up to current file version: 213462026/09/20 10:47:31 OK 20241026095416_initial_model.sql (91.55ms)13472026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (11.36ms)13482026/09/20 10:47:31 OK 20251218171726_add_pins.sql (5.39ms)13492026/09/20 10:47:31 OK 20241026095416_initial_model.sql (70.8ms)13502026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (6.96ms)13512026/09/20 10:47:31 OK 20251218171726_add_pins.sql (8.73ms)13522026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (26.31ms)13532026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (22.29ms)13542026/09/20 10:47:31 OK 20260905000000_add_claims.sql (14.2ms)13552026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (13.28ms)13562026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000013572026/09/20 10:47:31 OK 1_commit_pending_closure.sql (1.37ms)13582026/09/20 10:47:31 OK 2_object_stats_trigger.sql (291.71µs)13592026/09/20 10:47:31 goose: up to current file version: 213602026/09/20 10:47:31 OK 20260905000000_add_claims.sql (21.77ms)13612026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (4.13ms)13622026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000013632026/09/20 10:47:31 OK 1_commit_pending_closure.sql (997.42µs)13642026/09/20 10:47:31 OK 2_object_stats_trigger.sql (249.42µs)13652026/09/20 10:47:31 goose: up to current file version: 213662026-09-20 10:47:31.551 UTC [5786] ERROR: relation "goose_db_version" does not exist at character 3613672026-09-20 10:47:31.551 UTC [5786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13682026/09/20 10:47:31 INFO lead: acquired remote=192.0.2.1:123413692026/09/20 10:47:31 INFO lead: released remote=192.0.2.1:12341370--- PASS: TestLeadEndsOnShutdown (2.67s)1371=== CONT TestClientCADerivations1372=== NAME TestPinProtectsFromGC1373 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-5545-4069281544/TestPinProtectsFromGC2035954259/001/store/yg7bl5w44g38d9lyd7d8ci59rlxh4f8n-pinned-file.txt1374 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-5545-4069281544/TestPinProtectsFromGC2035954259/001/store/4dwz41kr0v2r8lghrrvsan10a3g6xqhx-unpinned-file.txt13752026/09/20 10:47:31 OK 20241026095416_initial_model.sql (65.63ms)13762026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (8.66ms)13772026/09/20 10:47:31 OK 20251218171726_add_pins.sql (14.39ms)13782026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (17.68ms)13792026/09/20 10:47:31 INFO lead: acquired remote=192.0.2.1:123413802026/09/20 10:47:31 OK 20260905000000_add_claims.sql (6.93ms)13812026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (11.5ms)13822026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000013832026/09/20 10:47:31 OK 1_commit_pending_closure.sql (1.18ms)13842026/09/20 10:47:31 OK 2_object_stats_trigger.sql (254.67µs)13852026/09/20 10:47:31 goose: up to current file version: 213862026/09/20 10:47:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13872026/09/20 10:47:31 INFO Received uploads request method=POST path=/api/pending_closures13882026/09/20 10:47:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13892026/09/20 10:47:31 INFO Uploading yg7bl5w44g38d9lyd7d8ci59rlxh4f8n-pinned-file.txt (128B)13902026/09/20 10:47:31 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13912026-09-20 10:47:31.796 UTC [5798] ERROR: relation "goose_db_version" does not exist at character 3613922026-09-20 10:47:31.796 UTC [5798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026/09/20 10:47:31 WARN Failed to register uploaded object key=yg7bl5w44g38d9lyd7d8ci59rlxh4f8n.ls error="server returned 404: 404 page not found\n"13942026/09/20 10:47:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13952026/09/20 10:47:31 INFO Signed narinfos id=1 count=113962026/09/20 10:47:31 INFO Uploading 1 narinfos13972026/09/20 10:47:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13982026/09/20 10:47:31 WARN Failed to register uploaded object key=yg7bl5w44g38d9lyd7d8ci59rlxh4f8n.narinfo error="server returned 404: 404 page not found\n"13992026/09/20 10:47:31 INFO Completed upload id=114002026/09/20 10:47:31 INFO Upload complete. (171ms)14012026/09/20 10:47:31 INFO lead: released remote=192.0.2.1:123414022026/09/20 10:47:31 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14032026/09/20 10:47:31 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1404--- PASS: TestService_NativeMTLS (2.43s)1405=== CONT TestClientErrorHandling1406=== RUN TestClientErrorHandling/InvalidStorePath1407=== PAUSE TestClientErrorHandling/InvalidStorePath1408=== RUN TestClientErrorHandling/InvalidAuthToken1409=== PAUSE TestClientErrorHandling/InvalidAuthToken1410=== RUN TestClientErrorHandling/ServerNotAvailable1411=== PAUSE TestClientErrorHandling/ServerNotAvailable1412=== CONT TestClientIntegration14132026/09/20 10:47:31 OK 20241026095416_initial_model.sql (36.38ms)14142026/09/20 10:47:31 INFO lead: acquired remote=192.0.2.1:123414152026/09/20 10:47:31 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)14162026/09/20 10:47:31 INFO lead: released remote=192.0.2.1:12341417--- PASS: TestLeadElectsOneAndHandsOver (2.74s)1418=== CONT TestService_readinessHandler14192026/09/20 10:47:31 OK 20251218171726_add_pins.sql (8.69ms)14202026/09/20 10:47:31 OK 20260628120000_add_object_size_and_stats.sql (13.21ms)14212026/09/20 10:47:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14222026/09/20 10:47:31 OK 20260905000000_add_claims.sql (17.52ms)14232026/09/20 10:47:31 OK 20260920000000_drop_claims.sql (14.25ms)14242026/09/20 10:47:31 goose: successfully migrated database to version: 2026092000000014252026/09/20 10:47:31 OK 1_commit_pending_closure.sql (911µs)14262026/09/20 10:47:31 OK 2_object_stats_trigger.sql (434.71µs)14272026/09/20 10:47:31 goose: up to current file version: 214282026/09/20 10:47:31 INFO Received uploads request method=POST path=/api/pending_closures14292026/09/20 10:47:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14302026/09/20 10:47:31 INFO Uploading 4dwz41kr0v2r8lghrrvsan10a3g6xqhx-unpinned-file.txt (128B)14312026/09/20 10:47:31 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14322026/09/20 10:47:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14332026/09/20 10:47:31 INFO Signed narinfos id=2 count=114342026/09/20 10:47:31 WARN Failed to register uploaded object key=4dwz41kr0v2r8lghrrvsan10a3g6xqhx.ls error="server returned 404: 404 page not found\n"14352026/09/20 10:47:31 INFO Uploading 1 narinfos14362026/09/20 10:47:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14372026/09/20 10:47:31 WARN Failed to register uploaded object key=4dwz41kr0v2r8lghrrvsan10a3g6xqhx.narinfo error="server returned 404: 404 page not found\n"14382026/09/20 10:47:31 INFO Completed upload id=214392026/09/20 10:47:31 INFO Upload complete. (119ms)1440--- PASS: TestMetricsInventory (2.47s)1441=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14422026/09/20 10:47:32 INFO Received create pin request method=POST path=/api/pins/myapp14432026/09/20 10:47:32 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-5545-4069281544/TestPinProtectsFromGC2035954259/001/store/yg7bl5w44g38d9lyd7d8ci59rlxh4f8n-pinned-file.txt narinfo_key=yg7bl5w44g38d9lyd7d8ci59rlxh4f8n.narinfo14442026/09/20 10:47:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures14452026/09/20 10:47:32 INFO Garbage collection started14462026/09/20 10:47:32 INFO Aborted multipart uploads count=014472026/09/20 10:47:32 WARN Force mode enabled - objects will be deleted immediately without grace period14482026-09-20 10:47:32.131 UTC [5815] ERROR: relation "goose_db_version" does not exist at character 3614492026-09-20 10:47:32.131 UTC [5815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026-09-20 10:47:32.148 UTC [5816] ERROR: relation "goose_db_version" does not exist at character 3614512026-09-20 10:47:32.148 UTC [5816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14522026/09/20 10:47:32 OK 20241026095416_initial_model.sql (39.06ms)14532026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)14542026/09/20 10:47:32 OK 20241026095416_initial_model.sql (34.1ms)14552026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (7.11ms)14562026/09/20 10:47:32 OK 20251218171726_add_pins.sql (15.81ms)14572026/09/20 10:47:32 OK 20251218171726_add_pins.sql (7.29ms)14582026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (16.66ms)14592026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (16.66ms)14602026/09/20 10:47:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=014612026/09/20 10:47:32 OK 20260905000000_add_claims.sql (34.87ms)14622026/09/20 10:47:32 OK 20260905000000_add_claims.sql (41.65ms)14632026/09/20 10:47:32 INFO Vacuumed table table=pending_closures14642026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (8.69ms)14652026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000014662026/09/20 10:47:32 OK 1_commit_pending_closure.sql (882.21µs)14672026/09/20 10:47:32 OK 2_object_stats_trigger.sql (220.04µs)14682026/09/20 10:47:32 goose: up to current file version: 214692026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (18.37ms)14702026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000014712026/09/20 10:47:32 OK 1_commit_pending_closure.sql (833.92µs)14722026/09/20 10:47:32 OK 2_object_stats_trigger.sql (418.71µs)14732026/09/20 10:47:32 goose: up to current file version: 214742026/09/20 10:47:32 INFO Vacuumed table table=pending_objects14752026/09/20 10:47:32 INFO Vacuumed table table=multipart_uploads1476=== NAME TestNARDeduplicationMetadataUploadBug1477 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-5545-4069281544/TestNARDeduplicationMetadataUploadBug1430438047/001/store/icsilxk854pp6v8slc9vp7n30n6qipiv-file1.txt14782026/09/20 10:47:32 INFO Vacuumed table table=closures14792026/09/20 10:47:32 INFO Vacuumed table table=objects14802026/09/20 10:47:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14812026-09-20 10:47:32.428 UTC [5827] ERROR: relation "goose_db_version" does not exist at character 3614822026-09-20 10:47:32.428 UTC [5827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures14842026/09/20 10:47:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14852026/09/20 10:47:32 INFO Uploading icsilxk854pp6v8slc9vp7n30n6qipiv-file1.txt (160B)14862026/09/20 10:47:32 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14872026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14882026/09/20 10:47:32 WARN Failed to register uploaded object key=icsilxk854pp6v8slc9vp7n30n6qipiv.ls error="server returned 404: 404 page not found\n"14892026/09/20 10:47:32 INFO Signed narinfos id=1 count=114902026/09/20 10:47:32 INFO Uploading 1 narinfos14912026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14922026/09/20 10:47:32 WARN Failed to register uploaded object key=icsilxk854pp6v8slc9vp7n30n6qipiv.narinfo error="server returned 404: 404 page not found\n"14932026/09/20 10:47:32 INFO Completed upload id=114942026/09/20 10:47:32 INFO Upload complete. (155ms)1495 metadata_upload_test.go:54: Retrieved narinfo from S3:1496 StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestNARDeduplicationMetadataUploadBug1430438047/001/store/icsilxk854pp6v8slc9vp7n30n6qipiv-file1.txt1497 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1498 Compression: zstd1499 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1500 NarSize: 1601501 References: 1502 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1503 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1504 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1505 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15062026/09/20 10:47:32 OK 20241026095416_initial_model.sql (56.77ms)15072026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)15082026/09/20 10:47:32 OK 20251218171726_add_pins.sql (3.7ms)15092026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (25.72ms)1510 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-5545-4069281544/TestNARDeduplicationMetadataUploadBug1430438047/001/store/0snhdghnrwps1x3q8ibjw4gijbi85gcf-file2.txt15112026/09/20 10:47:32 OK 20260905000000_add_claims.sql (16.56ms)15122026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (7.07ms)15132026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000015142026/09/20 10:47:32 OK 1_commit_pending_closure.sql (924.54µs)15152026/09/20 10:47:32 OK 2_object_stats_trigger.sql (427.88µs)15162026/09/20 10:47:32 goose: up to current file version: 21517=== NAME TestClientWithDependencies1518 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-5545-4069281544/TestClientWithDependencies4008854623/001/store/vvgzyvw0lisrswdsm35pkm401333yc87-test-script15192026/09/20 10:47:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1520=== RUN TestService_RequireScope_OIDC/builder_may_write1521=== PAUSE TestService_RequireScope_OIDC/builder_may_write1522=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1523=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1524=== RUN TestService_RequireScope_OIDC/ops_may_admin1525=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1526=== RUN TestService_RequireScope_OIDC/ops_may_not_write1527=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1528=== RUN TestService_RequireScope_OIDC/reader_may_not_write1529=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1530=== RUN TestService_RequireScope_OIDC/static_token_may_admin1531=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1532=== RUN TestService_RequireScope_OIDC/static_token_may_write1533=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1534=== RUN TestService_RequireScope_OIDC/reader_may_read1535=== PAUSE TestService_RequireScope_OIDC/reader_may_read1536=== RUN TestService_RequireScope_OIDC/writer_implies_read1537=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1538=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1539=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1540=== CONT TestService_healthCheckHandler15412026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures15422026/09/20 10:47:32 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1543=== NAME TestClientWithDependencies1544 client_integration_test.go:615: Found 1 dependencies (including self)15452026-09-20 10:47:32.692 UTC [5851] ERROR: relation "goose_db_version" does not exist at character 3615462026-09-20 10:47:32.692 UTC [5851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15472026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15482026/09/20 10:47:32 INFO Signed narinfos id=2 count=115492026/09/20 10:47:32 WARN Failed to register uploaded object key=0snhdghnrwps1x3q8ibjw4gijbi85gcf.ls error="server returned 404: 404 page not found\n"15502026/09/20 10:47:32 INFO Uploading 1 narinfos15512026/09/20 10:47:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15522026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15532026/09/20 10:47:32 WARN Failed to register uploaded object key=0snhdghnrwps1x3q8ibjw4gijbi85gcf.narinfo error="server returned 404: 404 page not found\n"15542026-09-20 10:47:32.711 UTC [5854] ERROR: relation "goose_db_version" does not exist at character 3615552026-09-20 10:47:32.711 UTC [5854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/09/20 10:47:32 INFO Completed upload id=215572026/09/20 10:47:32 INFO Upload complete. (116ms)1558=== NAME TestNARDeduplicationMetadataUploadBug1559 metadata_upload_test.go:76: Retrieved narinfo from S3:1560 StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestNARDeduplicationMetadataUploadBug1430438047/001/store/0snhdghnrwps1x3q8ibjw4gijbi85gcf-file2.txt1561 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1562 Compression: zstd1563 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1564 NarSize: 1601565 References: 1566 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1567 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1568 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1569 {"version":1,"root":{"type":"regular","size":44}}1570--- PASS: TestNARDeduplicationMetadataUploadBug (2.83s)1571=== CONT TestGCTaskStore_StartNew1572--- PASS: TestGCTaskStore_StartNew (0.00s)1573=== CONT TestCacheStatsHandler15742026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures15752026/09/20 10:47:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15762026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures15772026/09/20 10:47:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15782026/09/20 10:47:32 INFO Uploading vvgzyvw0lisrswdsm35pkm401333yc87-test-script (136B)15792026-09-20 10:47:32.791 UTC [5862] ERROR: relation "goose_db_version" does not exist at character 3615802026-09-20 10:47:32.791 UTC [5862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/09/20 10:47:32 WARN Failed to register uploaded object key=log/kjcjkh4qak8is48vv6i47hl6sa94rwqm-test-script.drv error="server returned 404: 404 page not found\n"15822026/09/20 10:47:32 OK 20241026095416_initial_model.sql (92.76ms)15832026/09/20 10:47:32 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15842026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (8.47ms)15852026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15862026/09/20 10:47:32 WARN Failed to register uploaded object key=vvgzyvw0lisrswdsm35pkm401333yc87.ls error="server returned 404: 404 page not found\n"15872026/09/20 10:47:32 INFO Signed narinfos id=1 count=115882026/09/20 10:47:32 INFO Uploading 1 narinfos15892026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15902026/09/20 10:47:32 WARN Failed to register uploaded object key=vvgzyvw0lisrswdsm35pkm401333yc87.narinfo error="server returned 404: 404 page not found\n"15912026/09/20 10:47:32 OK 20251218171726_add_pins.sql (7.35ms)15922026/09/20 10:47:32 OK 20241026095416_initial_model.sql (84.49ms)15932026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (756.71µs)15942026/09/20 10:47:32 INFO Completed upload id=115952026/09/20 10:47:32 INFO Upload complete. (109ms)15962026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)15972026/09/20 10:47:32 OK 20251218171726_add_pins.sql (1.96ms)1598=== NAME TestClientWithDependencies1599 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-5545-4069281544/TestClientWithDependencies4008854623/001/store) requires matching store prefix16002026/09/20 10:47:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16012026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)16022026/09/20 10:47:32 OK 20260905000000_add_claims.sql (3.48ms)16032026/09/20 10:47:32 OK 20241026095416_initial_model.sql (8.31ms)16042026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (2.45ms)16052026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000016062026/09/20 10:47:32 OK 20260905000000_add_claims.sql (2.83ms)1607--- PASS: TestClientWithDependencies (2.21s)1608=== CONT TestCacheConfigHandler1609=== RUN TestCacheConfigHandler/full_config,_no_issuer1610=== PAUSE TestCacheConfigHandler/full_config,_no_issuer16112026/09/20 10:47:32 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)1612=== RUN TestCacheConfigHandler/no_cache_url_configured1613=== PAUSE TestCacheConfigHandler/no_cache_url_configured1614=== RUN TestCacheConfigHandler/no_signing_keys1615=== PAUSE TestCacheConfigHandler/no_signing_keys1616=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1617=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1618=== CONT TestService_ReadScope_PublicByDefault16192026/09/20 10:47:32 OK 1_commit_pending_closure.sql (1.2ms)16202026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (1.92ms)16212026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000016222026/09/20 10:47:32 OK 20251218171726_add_pins.sql (1.78ms)16232026/09/20 10:47:32 OK 2_object_stats_trigger.sql (1.33ms)16242026/09/20 10:47:32 goose: up to current file version: 216252026/09/20 10:47:32 OK 1_commit_pending_closure.sql (3.04ms)16262026/09/20 10:47:32 OK 2_object_stats_trigger.sql (381.54µs)16272026/09/20 10:47:32 goose: up to current file version: 216282026/09/20 10:47:32 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)16292026/09/20 10:47:32 OK 20260905000000_add_claims.sql (11.75ms)16302026/09/20 10:47:32 OK 20260920000000_drop_claims.sql (16.13ms)16312026/09/20 10:47:32 goose: successfully migrated database to version: 2026092000000016322026/09/20 10:47:32 OK 1_commit_pending_closure.sql (1.1ms)16332026/09/20 10:47:32 OK 2_object_stats_trigger.sql (270.08µs)16342026/09/20 10:47:32 goose: up to current file version: 216352026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures16362026/09/20 10:47:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16372026/09/20 10:47:32 INFO Uploading gd87h0jyrhvc6886w88102xya4r1lbpc-shared-dep (136B)16382026/09/20 10:47:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16392026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16402026/09/20 10:47:32 WARN Failed to register uploaded object key=gd87h0jyrhvc6886w88102xya4r1lbpc.ls error="server returned 404: 404 page not found\n"16412026/09/20 10:47:32 INFO Signed narinfos id=2 count=116422026/09/20 10:47:32 INFO Uploading 1 narinfos16432026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16442026/09/20 10:47:32 WARN Failed to register uploaded object key=gd87h0jyrhvc6886w88102xya4r1lbpc.narinfo error="server returned 404: 404 page not found\n"16452026/09/20 10:47:32 INFO Completed upload id=216462026/09/20 10:47:32 INFO Upload complete. (126ms)16472026/09/20 10:47:32 INFO Received uploads request method=POST path=/api/pending_closures16482026/09/20 10:47:32 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16492026/09/20 10:47:32 INFO Uploading gd87h0jyrhvc6886w88102xya4r1lbpc-shared-dep (136B)16502026/09/20 10:47:32 INFO Uploading lf13w6ms4wadx69p8wjs1kiylv0cwb0z-top (256B)16512026/09/20 10:47:32 WARN Failed to register uploaded object key=nar/1g9lnrarrdqmn7w1p4zb5smz5yvp0yxa0w7av31k2hx4vwwq7y75.nar.zst error="server returned 404: 404 page not found\n"16522026/09/20 10:47:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16532026/09/20 10:47:32 WARN Failed to register uploaded object key=lf13w6ms4wadx69p8wjs1kiylv0cwb0z.ls error="server returned 404: 404 page not found\n"16542026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16552026/09/20 10:47:32 INFO Signed narinfos id=1 count=116562026/09/20 10:47:32 WARN Failed to register uploaded object key=gd87h0jyrhvc6886w88102xya4r1lbpc.ls error="server returned 404: 404 page not found\n"16572026/09/20 10:47:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16582026/09/20 10:47:32 INFO Signed narinfos id=3 count=116592026/09/20 10:47:32 INFO Uploading 2 narinfos16602026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16612026/09/20 10:47:32 WARN Failed to register uploaded object key=lf13w6ms4wadx69p8wjs1kiylv0cwb0z.narinfo error="server returned 404: 404 page not found\n"16622026/09/20 10:47:32 WARN Failed to register uploaded object key=gd87h0jyrhvc6886w88102xya4r1lbpc.narinfo error="server returned 404: 404 page not found\n"16632026/09/20 10:47:32 INFO Completed upload id=316642026/09/20 10:47:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16652026/09/20 10:47:32 INFO Completed upload id=116662026/09/20 10:47:32 INFO Upload complete. (316ms)1667=== NAME TestClientSharedPathCommittedMidPush1668 client_integration_test.go:680: Retrieved narinfo from S3:1669 StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestClientSharedPathCommittedMidPush3930760661/001/store/gd87h0jyrhvc6886w88102xya4r1lbpc-shared-dep1670 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1671 Compression: zstd1672 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821673 NarSize: 1361674 References: 1675 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1676 client_integration_test.go:680: Retrieved narinfo from S3:1677 StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestClientSharedPathCommittedMidPush3930760661/001/store/lf13w6ms4wadx69p8wjs1kiylv0cwb0z-top1678 URL: nar/1g9lnrarrdqmn7w1p4zb5smz5yvp0yxa0w7av31k2hx4vwwq7y75.nar.zst1679 Compression: zstd1680 NarHash: sha256:1g9lnrarrdqmn7w1p4zb5smz5yvp0yxa0w7av31k2hx4vwwq7y751681 NarSize: 2561682 References: /nix/var/nix/builds/nix-5545-4069281544/TestClientSharedPathCommittedMidPush3930760661/001/store/gd87h0jyrhvc6886w88102xya4r1lbpc-shared-dep1683 CA: text:sha256:116d9c00awqfdql7lrbdfd8imq6lbz5298rsr4533ldw4xwm1nvn1684--- PASS: TestClientSharedPathCommittedMidPush (1.83s)1685=== CONT TestService_AuthMiddleware_MTLSProxyHeader1686=== NAME TestClientIntegration1687 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-5545-4069281544/TestClientIntegration1347400535/002/store/7lkhf2pmc5x59grw18sxx3bw4qkmak9s-test-file.txt16882026/09/20 10:47:33 WARN readiness check failed error="closed pool"1689--- PASS: TestService_readinessHandler (1.23s)1690=== CONT TestService_ReadAuthMiddleware1691=== NAME TestClientCADerivations1692 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-5545-4069281544/TestClientCADerivations1163223858/001/store/cc7m0hzra74wnl0cwrsnvxgj077klg7z-ca-test16932026/09/20 10:47:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1694 client_ca_test.go:139: Found 1 dependencies (including self)16952026/09/20 10:47:33 INFO Received uploads request method=POST path=/api/pending_closures16962026/09/20 10:47:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16972026/09/20 10:47:33 INFO Uploading 7lkhf2pmc5x59grw18sxx3bw4qkmak9s-test-file.txt (152B)1698=== NAME TestOrphanedObjectsGCStressTest1699 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17002026/09/20 10:47:33 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17012026/09/20 10:47:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17022026/09/20 10:47:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17032026/09/20 10:47:33 WARN Failed to register uploaded object key=7lkhf2pmc5x59grw18sxx3bw4qkmak9s.ls error="server returned 404: 404 page not found\n"17042026/09/20 10:47:33 INFO Signed narinfos id=1 count=117052026/09/20 10:47:33 INFO Uploading 1 narinfos1706 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17072026/09/20 10:47:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17082026/09/20 10:47:33 WARN Failed to register uploaded object key=7lkhf2pmc5x59grw18sxx3bw4qkmak9s.narinfo error="server returned 404: 404 page not found\n"17092026/09/20 10:47:33 INFO Completed upload id=117102026/09/20 10:47:33 INFO Upload complete. (154ms)17112026/09/20 10:47:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17122026/09/20 10:47:33 WARN mTLS auth: bound subjects configured but subject DN unavailable17132026/09/20 10:47:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1714--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.25s)1715=== CONT TestService_AuthMiddleware_OIDC17162026/09/20 10:47:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49414/oidc17172026/09/20 10:47:33 INFO Received uploads request method=POST path=/api/pending_closures17182026-09-20 10:47:33.272 UTC [5898] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-20 10:47:33.272 UTC [5898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026/09/20 10:47:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17212026/09/20 10:47:33 INFO Uploading cc7m0hzra74wnl0cwrsnvxgj077klg7z-ca-test (144B)17222026/09/20 10:47:33 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17232026/09/20 10:47:33 WARN Failed to register uploaded object key=log/1s5jjfdwp4l7rr0h86ridcjvxlij29qm-ca-test.drv error="server returned 404: 404 page not found\n"17242026/09/20 10:47:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17252026/09/20 10:47:33 WARN Failed to register uploaded object key=cc7m0hzra74wnl0cwrsnvxgj077klg7z.ls error="server returned 404: 404 page not found\n"17262026/09/20 10:47:33 INFO Signed narinfos id=1 count=117272026/09/20 10:47:33 INFO Uploading 1 narinfos17282026/09/20 10:47:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17292026/09/20 10:47:33 WARN Failed to register uploaded object key=cc7m0hzra74wnl0cwrsnvxgj077klg7z.narinfo error="server returned 404: 404 page not found\n"17302026-09-20 10:47:33.295 UTC [5901] ERROR: relation "goose_db_version" does not exist at character 3617312026-09-20 10:47:33.295 UTC [5901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17322026/09/20 10:47:33 INFO All 1 paths already cached1733=== NAME TestClientIntegration1734 client_integration_test.go:312: Retrieved narinfo from S3:1735 StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestClientIntegration1347400535/002/store/7lkhf2pmc5x59grw18sxx3bw4qkmak9s-test-file.txt1736 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1737 Compression: zstd1738 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11739 NarSize: 1521740 References: 1741 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11742 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1743 client_integration_test.go:313: Decompressed .ls content (64 bytes):1744 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1745 client_integration_test.go:316: Testing garbage collection...17462026/09/20 10:47:33 INFO Completed upload id=117472026/09/20 10:47:33 INFO Upload complete. (107ms)1748=== NAME TestClientCADerivations1749 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-5545-4069281544/TestClientCADerivations1163223858/001/store/cc7m0hzra74wnl0cwrsnvxgj077klg7z-ca-test1750 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1751 Compression: zstd1752 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1753 NarSize: 1441754 References: 1755 Deriver: /nix/var/nix/builds/nix-5545-4069281544/TestClientCADerivations1163223858/001/store/1s5jjfdwp4l7rr0h86ridcjvxlij29qm-ca-test.drv1756 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1757 client_ca_test.go:185: Checking for realisation files in S3...17582026/09/20 10:47:33 OK 20241026095416_initial_model.sql (22ms)1759 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1760 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17612026/09/20 10:47:33 OK 20251210153512_drop_unused_gin_index.sql (747.25µs)17622026/09/20 10:47:33 OK 20251218171726_add_pins.sql (1.98ms)17632026/09/20 10:47:33 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)17642026/09/20 10:47:33 OK 20260905000000_add_claims.sql (1.67ms)17652026/09/20 10:47:33 OK 20260920000000_drop_claims.sql (1.38ms)17662026/09/20 10:47:33 goose: successfully migrated database to version: 2026092000000017672026/09/20 10:47:33 OK 20241026095416_initial_model.sql (6.9ms)17682026/09/20 10:47:33 OK 1_commit_pending_closure.sql (952.63µs)17692026/09/20 10:47:33 OK 20251210153512_drop_unused_gin_index.sql (426µs)17702026/09/20 10:47:33 OK 2_object_stats_trigger.sql (581.21µs)17712026/09/20 10:47:33 goose: up to current file version: 217722026/09/20 10:47:33 OK 20251218171726_add_pins.sql (2.31ms)17732026/09/20 10:47:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures17742026/09/20 10:47:33 INFO Garbage collection started17752026/09/20 10:47:33 INFO Aborted multipart uploads count=017762026/09/20 10:47:33 WARN Force mode enabled - objects will be deleted immediately without grace period17772026/09/20 10:47:33 OK 20260628120000_add_object_size_and_stats.sql (36.82ms)17782026/09/20 10:47:33 OK 20260905000000_add_claims.sql (23.99ms)17792026/09/20 10:47:33 OK 20260920000000_drop_claims.sql (1.06ms)17802026/09/20 10:47:33 goose: successfully migrated database to version: 2026092000000017812026/09/20 10:47:33 OK 1_commit_pending_closure.sql (1.31ms)17822026/09/20 10:47:33 OK 2_object_stats_trigger.sql (233.42µs)17832026/09/20 10:47:33 goose: up to current file version: 21784 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket42?endpoint=http://localhost:49273®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-5545-4069281544/TestClientCADerivations1163223858/001/store'1785 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11786--- PASS: TestClientCADerivations (1.87s)1787=== CONT TestClientMultipleUploads1788--- PASS: TestService_healthCheckHandler (0.85s)1789=== CONT TestGCMetrics17902026-09-20 10:47:33.497 UTC [5910] ERROR: relation "goose_db_version" does not exist at character 3617912026-09-20 10:47:33.497 UTC [5910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17922026/09/20 10:47:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017932026/09/20 10:47:33 INFO Vacuumed table table=pending_closures17942026/09/20 10:47:33 INFO Vacuumed table table=pending_objects17952026/09/20 10:47:33 INFO Vacuumed table table=multipart_uploads17962026/09/20 10:47:33 OK 20241026095416_initial_model.sql (63.14ms)17972026/09/20 10:47:33 OK 20251210153512_drop_unused_gin_index.sql (8.12ms)17982026/09/20 10:47:33 INFO Vacuumed table table=closures17992026/09/20 10:47:33 OK 20251218171726_add_pins.sql (17.58ms)18002026/09/20 10:47:33 INFO Vacuumed table table=objects18012026/09/20 10:47:33 OK 20260628120000_add_object_size_and_stats.sql (21.02ms)18022026/09/20 10:47:33 OK 20260905000000_add_claims.sql (2.98ms)18032026/09/20 10:47:33 OK 20260920000000_drop_claims.sql (669.38µs)18042026/09/20 10:47:33 goose: successfully migrated database to version: 2026092000000018052026/09/20 10:47:33 OK 1_commit_pending_closure.sql (914.92µs)18062026/09/20 10:47:33 OK 2_object_stats_trigger.sql (210.46µs)18072026/09/20 10:47:33 goose: up to current file version: 21808--- PASS: TestCacheStatsHandler (0.93s)1809=== CONT TestGCTaskStore_ConflictDifferentParams1810--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1811=== CONT TestGCTaskStore_DeduplicateSameParams1812--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1813=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18142026/09/20 10:47:33 INFO Received uploads request method=POST path=/1815=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18162026/09/20 10:47:33 INFO Received complete multipart upload request method=POST path=/1817=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18182026/09/20 10:47:33 INFO Received request for more parts method=POST path=/1819=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18202026/09/20 10:47:33 INFO Received uploads request method=POST path=/1821--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1822 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1823 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1824 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1825 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1826=== CONT TestIsValidUploadKey/narinfo1827=== CONT TestProxyWriteTimeout/narinfo1828=== CONT TestIsValidUploadKey/realisation1829=== CONT TestIsValidUploadKey/build_log_equals1830=== CONT TestIsValidUploadKey/build_log_question_mark1831=== CONT TestIsValidUploadKey/build_log_plus_in_name1832=== CONT TestIsValidUploadKey/build_log_home-manager_file1833=== CONT TestIsValidUploadKey/realisation_plus_in_output1834=== CONT TestIsValidUploadKey/unknown_type1835=== CONT TestIsValidUploadKey/empty_key1836=== CONT TestIsValidUploadKey/build_log1837=== CONT TestIsValidUploadKey/absolute1838=== CONT TestIsValidUploadKey/listing1839=== CONT TestIsValidUploadKey/traversal_nar1840=== CONT TestIsValidUploadKey/nar_plain1841=== CONT TestIsValidUploadKey/traversal1842=== CONT TestIsValidUploadKey/nar_xz1843=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1844=== CONT TestIsValidUploadKey/nar_zst1845=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1846=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1847=== CONT TestIsValidUploadKey/index.html1848=== CONT TestIsValidUploadKey/nix-cache-info1849--- PASS: TestIsValidUploadKey (0.02s)1850 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1851 --- PASS: TestIsValidUploadKey/realisation (0.00s)1852 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1853 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1854 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1855 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1856 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1857 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1858 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1859 --- PASS: TestIsValidUploadKey/build_log (0.00s)1860 --- PASS: TestIsValidUploadKey/absolute (0.00s)1861 --- PASS: TestIsValidUploadKey/listing (0.00s)1862 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1863 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1864 --- PASS: TestIsValidUploadKey/traversal (0.00s)1865 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1866 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1867 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1868 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1869 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1870 --- PASS: TestIsValidUploadKey/index.html (0.00s)1871 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1872=== CONT TestProxyWriteTimeout/10_GiB_nar1873=== CONT TestProxyWriteTimeout/unknown_size1874=== CONT TestProxyWriteTimeout/1_GiB_nar1875--- PASS: TestProxyWriteTimeout (0.00s)1876 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1877 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1878 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1879 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1880=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18812026/09/20 10:47:33 INFO Received uploads request method=POST path=/18822026-09-20 10:47:33.698 UTC [5913] ERROR: relation "goose_db_version" does not exist at character 3618832026-09-20 10:47:33.698 UTC [5913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18842026/09/20 10:47:33 OK 20241026095416_initial_model.sql (68.79ms)18852026/09/20 10:47:33 OK 20251210153512_drop_unused_gin_index.sql (6.67ms)1886--- PASS: TestService_ReadScope_PublicByDefault (0.98s)1887=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18882026/09/20 10:47:33 INFO Received request for more parts method=POST path=/18892026/09/20 10:47:33 OK 20251218171726_add_pins.sql (8.17ms)18902026/09/20 10:47:33 OK 20260628120000_add_object_size_and_stats.sql (1.8ms)18912026/09/20 10:47:33 OK 20260905000000_add_claims.sql (3.78ms)18922026/09/20 10:47:33 OK 20260920000000_drop_claims.sql (1.49ms)18932026/09/20 10:47:33 goose: successfully migrated database to version: 2026092000000018942026/09/20 10:47:33 OK 1_commit_pending_closure.sql (1.02ms)18952026/09/20 10:47:33 OK 2_object_stats_trigger.sql (335.29µs)18962026/09/20 10:47:33 goose: up to current file version: 218972026-09-20 10:47:33.836 UTC [5914] ERROR: relation "goose_db_version" does not exist at character 3618982026-09-20 10:47:33.836 UTC [5914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1899=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19002026/09/20 10:47:33 INFO Received complete multipart upload request method=POST path=/1901=== CONT TestIsValidCachePath/narinfo1902=== CONT TestIsValidCachePath/index.html1903=== CONT TestIsValidCachePath/short_hash1904=== CONT TestIsValidCachePath/wrong_extension1905=== CONT TestIsValidCachePath/leading_slash1906=== CONT TestIsValidCachePath/empty1907=== CONT TestIsValidCachePath/random_path1908=== CONT TestIsValidCachePath/invalid_char_u1909=== CONT TestIsValidCachePath/invalid_char_e1910=== CONT TestIsValidCachePath/traversal_in_middle1911=== CONT TestIsValidCachePath/traversal_parent1912=== CONT TestIsValidCachePath/nar_uncompressed1913=== CONT TestIsValidCachePath/nix-cache-info1914=== CONT TestIsValidCachePath/realisation1915=== CONT TestIsValidCachePath/log1916=== CONT TestIsValidCachePath/ls1917=== CONT TestIsValidCachePath/nar_xz1918=== CONT TestIsValidCachePath/nar_bz21919=== CONT TestIsValidCachePath/nar_zst1920=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1921--- PASS: TestIsValidCachePath (0.00s)1922 --- PASS: TestIsValidCachePath/narinfo (0.00s)1923 --- PASS: TestIsValidCachePath/index.html (0.00s)1924 --- PASS: TestIsValidCachePath/short_hash (0.00s)1925 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1926 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1927 --- PASS: TestIsValidCachePath/empty (0.00s)1928 --- PASS: TestIsValidCachePath/random_path (0.00s)1929 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1930 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1931 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1932 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1933 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1934 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1935 --- PASS: TestIsValidCachePath/realisation (0.00s)1936 --- PASS: TestIsValidCachePath/log (0.00s)1937 --- PASS: TestIsValidCachePath/ls (0.00s)1938 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1939 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1940 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1941 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1942=== CONT TestParseSingleRange/none1943=== CONT TestParseSingleRange/open-ended1944=== CONT TestParseSingleRange/start_far_past_EOF1945=== CONT TestParseSingleRange/start_past_EOF1946=== CONT TestParseSingleRange/single_byte1947=== CONT TestParseSingleRange/suffix_exceeds_size1948=== CONT TestParseSingleRange/suffix1949=== CONT TestParseSingleRange/end_clamped_to_size1950=== CONT TestParseSingleRange/malformed_both_empty1951=== CONT TestParseSingleRange/closed1952=== CONT TestParseSingleRange/malformed_end_before_start1953=== CONT TestParseSingleRange/multi-range_ignored1954=== CONT TestParseSingleRange/malformed_no_dash1955=== CONT TestParseSingleRange/unknown_unit1956--- PASS: TestParseSingleRange (0.00s)1957 --- PASS: TestParseSingleRange/none (0.00s)1958 --- PASS: TestParseSingleRange/open-ended (0.00s)1959 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1960 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1961 --- PASS: TestParseSingleRange/single_byte (0.00s)1962 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1963 --- PASS: TestParseSingleRange/suffix (0.00s)1964 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1965 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1966 --- PASS: TestParseSingleRange/closed (0.00s)1967 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1968 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1969 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1970 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1971=== CONT TestResolveDBConnectionString/flag_wins1972=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1973=== CONT TestResolveDBConnectionString/nothing_configured1974=== CONT TestResolveDBConnectionString/missing_file_is_an_error1975=== CONT TestResolveDBConnectionString/file_when_flag_empty1976=== CONT TestClientErrorHandling/InvalidStorePath1977--- PASS: TestResolveDBConnectionString (0.01s)1978 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1979 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1980 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1981 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1982 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19832026/09/20 10:47:33 OK 20241026095416_initial_model.sql (43.83ms)19842026/09/20 10:47:33 OK 20251210153512_drop_unused_gin_index.sql (6.41ms)1985--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1986 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1987 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1988 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)1989=== CONT TestClientErrorHandling/ServerNotAvailable19902026/09/20 10:47:33 OK 20251218171726_add_pins.sql (22.25ms)19912026/09/20 10:47:33 OK 20260628120000_add_object_size_and_stats.sql (18.52ms)1992--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.00s)1993=== CONT TestClientErrorHandling/InvalidAuthToken19942026/09/20 10:47:33 OK 20260905000000_add_claims.sql (15.5ms)19952026/09/20 10:47:33 OK 20260920000000_drop_claims.sql (1.25ms)19962026/09/20 10:47:33 goose: successfully migrated database to version: 2026092000000019972026/09/20 10:47:33 OK 1_commit_pending_closure.sql (988.75µs)19982026/09/20 10:47:33 OK 2_object_stats_trigger.sql (336.96µs)19992026/09/20 10:47:33 goose: up to current file version: 220002026-09-20 10:47:33.993 UTC [5920] ERROR: relation "goose_db_version" does not exist at character 3620012026-09-20 10:47:33.993 UTC [5920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20022026/09/20 10:47:34 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02003=== NAME TestPinProtectsFromGC2004 client_integration_test.go:794: Pin successfully protected closure from garbage collection2005--- PASS: TestPinProtectsFromGC (5.52s)2006=== CONT TestService_RequireScope_OIDC/builder_may_write20072026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[write]2008=== CONT TestService_RequireScope_OIDC/static_token_may_admin2009=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2010=== CONT TestService_RequireScope_OIDC/writer_implies_read20112026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[write]2012=== CONT TestService_RequireScope_OIDC/reader_may_read20132026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[read]2014=== CONT TestService_RequireScope_OIDC/static_token_may_write2015=== CONT TestService_RequireScope_OIDC/ops_may_not_write20162026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[admin]2017=== CONT TestService_RequireScope_OIDC/reader_may_not_write20182026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[read]2019=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20202026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[write]2021=== CONT TestService_RequireScope_OIDC/ops_may_admin20222026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[admin]2023=== CONT TestCacheConfigHandler/full_config,_no_issuer2024=== CONT TestCacheConfigHandler/no_signing_keys2025=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2026=== CONT TestCacheConfigHandler/no_cache_url_configured2027--- PASS: TestCacheConfigHandler (0.00s)2028 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2029 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2030 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2031 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2032--- PASS: TestService_RequireScope_OIDC (1.47s)2033 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2041 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)20432026/09/20 10:47:34 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20442026/09/20 10:47:34 OK 20241026095416_initial_model.sql (53.65ms)20452026/09/20 10:47:34 OK 20251210153512_drop_unused_gin_index.sql (11.42ms)20462026/09/20 10:47:34 OK 20251218171726_add_pins.sql (19.03ms)20472026/09/20 10:47:34 OK 20260628120000_add_object_size_and_stats.sql (19.26ms)2048--- PASS: TestService_ReadAuthMiddleware (1.05s)20492026/09/20 10:47:34 OK 20260905000000_add_claims.sql (19.9ms)20502026/09/20 10:47:34 OK 20260920000000_drop_claims.sql (5.19ms)20512026/09/20 10:47:34 goose: successfully migrated database to version: 2026092000000020522026/09/20 10:47:34 OK 1_commit_pending_closure.sql (2.47ms)20532026/09/20 10:47:34 OK 2_object_stats_trigger.sql (1.97ms)20542026/09/20 10:47:34 goose: up to current file version: 220552026/09/20 10:47:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.826039ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20562026-09-20 10:47:34.197 UTC [5924] ERROR: relation "goose_db_version" does not exist at character 3620572026-09-20 10:47:34.197 UTC [5924] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20582026-09-20 10:47:34.215 UTC [5925] ERROR: relation "goose_db_version" does not exist at character 3620592026-09-20 10:47:34.215 UTC [5925] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2060=== NAME TestOrphanedObjectsGCStressTest2061 orphaned_objects_gc_test.go:509: Stress test completed successfully:2062 orphaned_objects_gc_test.go:510: - Active objects preserved: 202063 orphaned_objects_gc_test.go:511: - Objects deleted: 2102064 orphaned_objects_gc_test.go:512: - Total GC'd: 2102065--- PASS: TestOrphanedObjectsGCStressTest (6.79s)20662026/09/20 10:47:34 OK 20241026095416_initial_model.sql (46.82ms)20672026/09/20 10:47:34 OK 20251210153512_drop_unused_gin_index.sql (9.26ms)20682026/09/20 10:47:34 OK 20251218171726_add_pins.sql (11.1ms)20692026/09/20 10:47:34 OK 20241026095416_initial_model.sql (70.61ms)20702026/09/20 10:47:34 OK 20251210153512_drop_unused_gin_index.sql (4.96ms)20712026/09/20 10:47:34 OK 20260628120000_add_object_size_and_stats.sql (15.42ms)20722026/09/20 10:47:34 OK 20251218171726_add_pins.sql (6.25ms)20732026/09/20 10:47:34 OK 20260628120000_add_object_size_and_stats.sql (18.93ms)20742026/09/20 10:47:34 OK 20260905000000_add_claims.sql (24.61ms)2075=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2076=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2077=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2078=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2079=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2080=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2081=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2082=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2083=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2084=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2085=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20862026/09/20 10:47:34 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]2087=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20882026/09/20 10:47:34 OK 20260920000000_drop_claims.sql (1.69ms)20892026/09/20 10:47:34 goose: successfully migrated database to version: 2026092000000020902026/09/20 10:47:34 OK 20260905000000_add_claims.sql (1.96ms)20912026/09/20 10:47:34 WARN Authentication failed token_preview=eyJhbGciOi...N3retNjk0w token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20922026/09/20 10:47:34 INFO OIDC auth successful provider=test scopes=[write]2093--- PASS: TestService_AuthMiddleware_OIDC (1.08s)2094 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2095 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2096 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2097 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)20982026/09/20 10:47:34 OK 20260920000000_drop_claims.sql (1.21ms)20992026/09/20 10:47:34 goose: successfully migrated database to version: 2026092000000021002026/09/20 10:47:34 OK 1_commit_pending_closure.sql (1.55ms)21012026/09/20 10:47:34 OK 2_object_stats_trigger.sql (330µs)21022026/09/20 10:47:34 goose: up to current file version: 221032026/09/20 10:47:34 OK 1_commit_pending_closure.sql (1.14ms)21042026/09/20 10:47:34 OK 2_object_stats_trigger.sql (274.75µs)21052026/09/20 10:47:34 goose: up to current file version: 221062026/09/20 10:47:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.442006ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21072026-09-20 10:47:34.529 UTC [5928] ERROR: relation "goose_db_version" does not exist at character 3621082026-09-20 10:47:34.529 UTC [5928] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2109=== NAME TestClientMultipleUploads2110 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-5545-4069281544/TestClientMultipleUploads809688583/001/store/jfg4vbiqqang6kadl8jy4q52m12hs3cg-test-file-0.txt21112026/09/20 10:47:34 OK 20241026095416_initial_model.sql (21.62ms)21122026/09/20 10:47:34 OK 20251210153512_drop_unused_gin_index.sql (5.22ms)21132026/09/20 10:47:34 OK 20251218171726_add_pins.sql (5.97ms)21142026/09/20 10:47:34 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)2115 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-5545-4069281544/TestClientMultipleUploads809688583/001/store/g9bh2jbws8sxs6fscjmih2gdf5i1wzc2-test-file-1.txt21162026-09-20 10:47:34.590 UTC [5931] ERROR: relation "goose_db_version" does not exist at character 3621172026-09-20 10:47:34.590 UTC [5931] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21182026/09/20 10:47:34 OK 20260905000000_add_claims.sql (10ms)21192026/09/20 10:47:34 OK 20260920000000_drop_claims.sql (3.71ms)21202026/09/20 10:47:34 goose: successfully migrated database to version: 2026092000000021212026/09/20 10:47:34 OK 1_commit_pending_closure.sql (745.92µs)21222026/09/20 10:47:34 OK 2_object_stats_trigger.sql (211.92µs)21232026/09/20 10:47:34 goose: up to current file version: 221242026/09/20 10:47:34 INFO Aborted multipart uploads count=021252026/09/20 10:47:34 WARN Force mode enabled - objects will be deleted immediately without grace period21262026/09/20 10:47:34 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=021272026/09/20 10:47:34 INFO Vacuumed table table=pending_closures21282026/09/20 10:47:34 INFO Vacuumed table table=pending_objects21292026/09/20 10:47:34 INFO Vacuumed table table=multipart_uploads21302026/09/20 10:47:34 INFO Vacuumed table table=closures21312026/09/20 10:47:34 INFO Vacuumed table table=objects2132--- PASS: TestGCMetrics (1.12s)21332026/09/20 10:47:34 OK 20241026095416_initial_model.sql (24.31ms)21342026/09/20 10:47:34 OK 20251210153512_drop_unused_gin_index.sql (443.04µs)2135=== NAME TestClientMultipleUploads2136 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-5545-4069281544/TestClientMultipleUploads809688583/001/store/9mhmfbhzw8l67cwmgxjdbwbd7vp5awnn-test-file-2.txt21372026/09/20 10:47:34 OK 20251218171726_add_pins.sql (1.51ms)21382026/09/20 10:47:34 OK 20260628120000_add_object_size_and_stats.sql (8.49ms)21392026/09/20 10:47:34 OK 20260905000000_add_claims.sql (10.85ms)21402026/09/20 10:47:34 OK 20260920000000_drop_claims.sql (5.69ms)21412026/09/20 10:47:34 goose: successfully migrated database to version: 2026092000000021422026/09/20 10:47:34 OK 1_commit_pending_closure.sql (830.46µs)21432026/09/20 10:47:34 OK 2_object_stats_trigger.sql (222.96µs)21442026/09/20 10:47:34 goose: up to current file version: 221452026/09/20 10:47:34 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21462026/09/20 10:47:34 INFO Received uploads request method=POST path=/api/pending_closures21472026/09/20 10:47:34 INFO Received uploads request method=POST path=/api/pending_closures21482026/09/20 10:47:34 INFO Received uploads request method=POST path=/api/pending_closures21492026/09/20 10:47:34 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21502026/09/20 10:47:34 INFO Uploading jfg4vbiqqang6kadl8jy4q52m12hs3cg-test-file-0.txt (160B)21512026/09/20 10:47:34 INFO Uploading 9mhmfbhzw8l67cwmgxjdbwbd7vp5awnn-test-file-2.txt (160B)21522026/09/20 10:47:34 INFO Uploading g9bh2jbws8sxs6fscjmih2gdf5i1wzc2-test-file-1.txt (160B)21532026/09/20 10:47:34 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21542026/09/20 10:47:34 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21552026/09/20 10:47:34 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21562026/09/20 10:47:34 WARN Failed to register uploaded object key=g9bh2jbws8sxs6fscjmih2gdf5i1wzc2.ls error="server returned 404: 404 page not found\n"21572026/09/20 10:47:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21582026/09/20 10:47:34 WARN Failed to register uploaded object key=9mhmfbhzw8l67cwmgxjdbwbd7vp5awnn.ls error="server returned 404: 404 page not found\n"21592026/09/20 10:47:34 WARN Failed to register uploaded object key=jfg4vbiqqang6kadl8jy4q52m12hs3cg.ls error="server returned 404: 404 page not found\n"21602026/09/20 10:47:34 INFO Signed narinfos id=2 count=121612026/09/20 10:47:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21622026/09/20 10:47:34 INFO Signed narinfos id=3 count=121632026/09/20 10:47:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21642026/09/20 10:47:34 INFO Signed narinfos id=1 count=121652026/09/20 10:47:34 INFO Uploading 3 narinfos21662026/09/20 10:47:34 WARN Failed to register uploaded object key=jfg4vbiqqang6kadl8jy4q52m12hs3cg.narinfo error="server returned 404: 404 page not found\n"21672026/09/20 10:47:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21682026/09/20 10:47:34 WARN Failed to register uploaded object key=9mhmfbhzw8l67cwmgxjdbwbd7vp5awnn.narinfo error="server returned 404: 404 page not found\n"21692026/09/20 10:47:34 WARN Failed to register uploaded object key=g9bh2jbws8sxs6fscjmih2gdf5i1wzc2.narinfo error="server returned 404: 404 page not found\n"21702026/09/20 10:47:34 INFO Completed upload id=121712026/09/20 10:47:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21722026/09/20 10:47:34 INFO Completed upload id=221732026/09/20 10:47:34 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21742026/09/20 10:47:34 INFO Completed upload id=321752026/09/20 10:47:34 INFO Upload complete. (103ms)2176 client_integration_test.go:369: Uploaded 3 paths in 132.455625ms2177--- PASS: TestClientMultipleUploads (1.35s)21782026/09/20 10:47:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.152474ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21792026/09/20 10:47:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21802026/09/20 10:47:34 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21812026/09/20 10:47:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21822026/09/20 10:47:35 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02183=== NAME TestClientIntegration2184 client_integration_test.go:323: Objects in database after GC:2185 client_integration_test.go:323: Successfully deleted all objects with GC --force2186--- PASS: TestClientIntegration (3.49s)21872026/09/20 10:47:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.757271066s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21882026/09/20 10:47:37 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21892026/09/20 10:47:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.999627ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21902026/09/20 10:47:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.081946ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21912026/09/20 10:47:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=726.700668ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/09/20 10:47:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.535600275s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21932026/09/20 10:47:40 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 127.0.0.1:19999: connect: connection refused"21942026/09/20 10:47:40 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21952026/09/20 10:47:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.031415ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21962026/09/20 10:47:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=420.735594ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21972026/09/20 10:47:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=797.767375ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21982026/09/20 10:47:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.65391323s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2199--- PASS: TestClientErrorHandling (0.00s)2200 --- PASS: TestClientErrorHandling/InvalidStorePath (0.85s)2201 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.90s)2202 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.70s)2203PASS2204{"timestamp":"2026-09-20T10:47:43.645014Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49320","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}22052026-09-20 10:47:43.745 UTC [5585] LOG: received smart shutdown request22062026-09-20 10:47:43.746 UTC [5585] LOG: background worker "logical replication launcher" (PID 5596) exited with exit code 122072026-09-20 10:47:43.749 UTC [5590] LOG: shutting down22082026-09-20 10:47:43.749 UTC [5590] LOG: checkpoint starting: shutdown immediate22092026-09-20 10:47:44.808 UTC [5590] LOG: checkpoint complete: wrote 12880 buffers (78.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.744 s, sync=0.309 s, total=1.060 s; sync files=18404, longest=0.001 s, average=0.001 s; distance=255508 kB, estimate=255508 kB; lsn=0/11112108, redo lsn=0/1111210822102026-09-20 10:47:44.812 UTC [5585] LOG: database system is shut down2211Running OIDC tests...2212=== RUN TestGlobMatch2213=== PAUSE TestGlobMatch2214=== RUN TestAudienceForIssuer2215=== PAUSE TestAudienceForIssuer2216=== RUN TestValidateToken_ValidToken2217=== PAUSE TestValidateToken_ValidToken2218=== RUN TestValidateToken_WrongAudience2219=== PAUSE TestValidateToken_WrongAudience2220=== RUN TestValidateToken_Expired2221=== PAUSE TestValidateToken_Expired2222=== RUN TestValidateToken_BoundClaimsMismatch2223=== PAUSE TestValidateToken_BoundClaimsMismatch2224=== RUN TestValidateToken_BoundSubjectMismatch2225=== PAUSE TestValidateToken_BoundSubjectMismatch2226=== RUN TestValidateToken_MultipleProviders2227=== PAUSE TestValidateToken_MultipleProviders2228=== RUN TestValidateToken_NoMatchingProvider2229=== PAUSE TestValidateToken_NoMatchingProvider2230=== RUN TestValidateToken_KubernetesServiceAccount2231=== PAUSE TestValidateToken_KubernetesServiceAccount2232=== RUN TestNewValidator_KubernetesRequiresCA2233=== PAUSE TestNewValidator_KubernetesRequiresCA2234=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2235=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2236=== RUN TestScopes_LegacyProviderDefaultsToWrite2237=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2238=== RUN TestScopes_Rules2239=== PAUSE TestScopes_Rules2240=== RUN TestScopes_ConfigValidation2241=== PAUSE TestScopes_ConfigValidation2242=== CONT TestGlobMatch2243=== CONT TestValidateToken_Expired2244=== RUN TestGlobMatch/foo_foo2245=== PAUSE TestGlobMatch/foo_foo2246=== CONT TestValidateToken_WrongAudience2247=== CONT TestValidateToken_ValidToken2248=== CONT TestAudienceForIssuer2249--- PASS: TestAudienceForIssuer (0.00s)2250=== CONT TestScopes_Rules2251=== CONT TestValidateToken_MultipleProviders2252=== CONT TestValidateToken_BoundClaimsMismatch2253=== CONT TestScopes_LegacyProviderDefaultsToWrite2254=== CONT TestScopes_ConfigValidation2255=== CONT TestValidateToken_NoMatchingProvider2256=== RUN TestGlobMatch/foo_bar2257=== PAUSE TestGlobMatch/foo_bar2258=== RUN TestGlobMatch/*_2259=== PAUSE TestGlobMatch/*_2260=== RUN TestGlobMatch/*_anything2261=== PAUSE TestGlobMatch/*_anything2262=== RUN TestGlobMatch/foo*_foo2263=== PAUSE TestGlobMatch/foo*_foo2264=== RUN TestGlobMatch/foo*_foobar2265=== PAUSE TestGlobMatch/foo*_foobar2266=== RUN TestGlobMatch/foo*_bar2267=== PAUSE TestGlobMatch/foo*_bar2268=== RUN TestGlobMatch/*bar_bar2269=== PAUSE TestGlobMatch/*bar_bar2270=== RUN TestGlobMatch/*bar_foobar2271=== PAUSE TestGlobMatch/*bar_foobar2272=== RUN TestGlobMatch/*bar_foo2273=== PAUSE TestGlobMatch/*bar_foo2274=== RUN TestGlobMatch/foo*bar_foobar2275=== PAUSE TestGlobMatch/foo*bar_foobar2276=== RUN TestGlobMatch/foo*bar_foo123bar2277=== PAUSE TestGlobMatch/foo*bar_foo123bar2278=== RUN TestGlobMatch/foo*bar_foobarbaz2279=== PAUSE TestGlobMatch/foo*bar_foobarbaz2280=== RUN TestGlobMatch/*/*_foo/bar2281=== PAUSE TestGlobMatch/*/*_foo/bar2282=== RUN TestGlobMatch/*/*_foo2283=== PAUSE TestGlobMatch/*/*_foo2284=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2285=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2286=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02287=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02288=== RUN TestGlobMatch/refs/*/main_refs/heads/main2289=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2290=== RUN TestGlobMatch/fo?_foo2291=== PAUSE TestGlobMatch/fo?_foo2292=== RUN TestGlobMatch/fo?_fo2293=== PAUSE TestGlobMatch/fo?_fo2294=== RUN TestGlobMatch/fo?_fooo2295=== PAUSE TestGlobMatch/fo?_fooo2296=== RUN TestGlobMatch/?oo_foo2297=== PAUSE TestGlobMatch/?oo_foo2298=== RUN TestGlobMatch/?oo_boo2299=== PAUSE TestGlobMatch/?oo_boo2300=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2301=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2302=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2303=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2304=== CONT TestNewValidator_KubernetesRequiresCA23052026/09/20 10:47:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49487/oidc23062026/09/20 10:47:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49482/oidc23072026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49491/oidc23082026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49485/oidc23092026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49484/oidc23102026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49486/oidc2311--- PASS: TestScopes_ConfigValidation (0.00s)2312=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23132026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49488/oidc23142026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49483/oidc23152026/09/20 10:47:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49490/oidc2316--- PASS: TestValidateToken_Expired (0.01s)2317=== CONT TestValidateToken_KubernetesServiceAccount2318--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2319=== CONT TestValidateToken_BoundSubjectMismatch2320--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2321=== CONT TestGlobMatch/foo_foo2322=== CONT TestGlobMatch/*/*_foo/bar2323=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2324=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2325=== CONT TestGlobMatch/?oo_boo2326=== CONT TestGlobMatch/?oo_foo2327=== CONT TestGlobMatch/fo?_fooo2328=== CONT TestGlobMatch/fo?_fo2329=== CONT TestGlobMatch/fo?_foo2330=== CONT TestGlobMatch/refs/*/main_refs/heads/main2331=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02332=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2333=== CONT TestGlobMatch/*bar_bar2334=== CONT TestGlobMatch/foo*bar_foobarbaz2335=== CONT TestGlobMatch/foo*bar_foo123bar2336=== CONT TestGlobMatch/foo*bar_foobar2337=== CONT TestGlobMatch/*bar_foo2338=== CONT TestGlobMatch/*bar_foobar2339=== CONT TestGlobMatch/foo*_foo2340=== CONT TestGlobMatch/foo*_bar2341=== CONT TestGlobMatch/foo*_foobar2342=== CONT TestGlobMatch/*_2343=== CONT TestGlobMatch/*_anything2344=== CONT TestGlobMatch/foo_bar2345--- PASS: TestValidateToken_WrongAudience (0.01s)2346=== CONT TestGlobMatch/*/*_foo2347--- PASS: TestGlobMatch (0.00s)2348 --- PASS: TestGlobMatch/foo_foo (0.00s)2349 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2350 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2351 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2352 --- PASS: TestGlobMatch/?oo_boo (0.00s)2353 --- PASS: TestGlobMatch/?oo_foo (0.00s)2354 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2355 --- PASS: TestGlobMatch/fo?_fo (0.00s)2356 --- PASS: TestGlobMatch/fo?_foo (0.00s)2357 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2358 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2359 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2360 --- PASS: TestGlobMatch/*bar_bar (0.00s)2361 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2362 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2363 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2364 --- PASS: TestGlobMatch/*bar_foo (0.00s)2365 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2366 --- PASS: TestGlobMatch/foo*_foo (0.00s)2367 --- PASS: TestGlobMatch/foo*_bar (0.00s)2368 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2369 --- PASS: TestGlobMatch/*_ (0.00s)2370 --- PASS: TestGlobMatch/*_anything (0.00s)2371 --- PASS: TestGlobMatch/foo_bar (0.00s)2372 --- PASS: TestGlobMatch/*/*_foo (0.00s)2373--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)23742026/09/20 10:47:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323752026/09/20 10:47:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49505/oidc2376--- PASS: TestValidateToken_ValidToken (0.01s)2377--- PASS: TestValidateToken_MultipleProviders (0.01s)2378--- PASS: TestValidateToken_BoundSubjectMismatch (0.00s)23792026/09/20 10:47:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:495042380--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2381--- PASS: TestScopes_Rules (0.02s)2382--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)23832026/09/20 10:47:45 http: TLS handshake error from 127.0.0.1:49502: remote error: tls: bad certificate2384--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2385PASS2386Running hook tests...2387=== RUN TestSendPathsEmpty2388=== PAUSE TestSendPathsEmpty2389=== RUN TestQueueEnqueueAndFetch2390=== PAUSE TestQueueEnqueueAndFetch2391=== RUN TestQueueDeduplication2392=== PAUSE TestQueueDeduplication2393=== RUN TestQueueRemove2394=== PAUSE TestQueueRemove2395=== RUN TestQueueFetchBatchLimit2396=== PAUSE TestQueueFetchBatchLimit2397=== RUN TestQueueRetryMovesToBack2398=== PAUSE TestQueueRetryMovesToBack2399=== RUN TestQueueFetchRemoveLifecycle2400=== PAUSE TestQueueFetchRemoveLifecycle2401=== RUN TestQueueConcurrentWriters2402=== PAUSE TestQueueConcurrentWriters2403=== RUN TestQueueRemoveLargeClosure2404=== PAUSE TestQueueRemoveLargeClosure2405=== RUN TestServerClientIntegration2406=== PAUSE TestServerClientIntegration2407=== RUN TestServerQueueError2408=== PAUSE TestServerQueueError2409=== RUN TestGetListenerSocketActivation2410 server_test.go:210: === RUN TestGetListenerSocketActivation2411 --- PASS: TestGetListenerSocketActivation (0.00s)2412 PASS2413 2414--- PASS: TestGetListenerSocketActivation (0.01s)2415=== RUN TestDrainIsolatesPoisonPath2416=== PAUSE TestDrainIsolatesPoisonPath2417=== RUN TestRunNotBlockedByPoisonHead2418=== PAUSE TestRunNotBlockedByPoisonHead2419=== RUN TestDrainGivesUpWhenServerDown2420=== PAUSE TestDrainGivesUpWhenServerDown2421=== RUN TestFailedPathPrunedByLaterClosure2422=== PAUSE TestFailedPathPrunedByLaterClosure2423=== RUN TestWorkerUploadsAndRemoves2424=== PAUSE TestWorkerUploadsAndRemoves2425=== RUN TestWorkerSkipsGCdPaths2426=== PAUSE TestWorkerSkipsGCdPaths2427=== RUN TestWorkerPrunesClosureDeps2428=== PAUSE TestWorkerPrunesClosureDeps2429=== RUN TestDrainTimeout2430=== PAUSE TestDrainTimeout2431=== CONT TestSendPathsEmpty2432=== CONT TestServerQueueError2433=== CONT TestWorkerUploadsAndRemoves2434--- PASS: TestSendPathsEmpty (0.00s)2435=== CONT TestServerClientIntegration2436=== CONT TestQueueRemoveLargeClosure2437=== CONT TestQueueConcurrentWriters2438=== CONT TestQueueFetchRemoveLifecycle2439=== CONT TestQueueRetryMovesToBack2440=== CONT TestQueueFetchBatchLimit2441=== CONT TestQueueRemove2442=== CONT TestQueueDeduplication24432026/09/20 10:47:46 ERROR Failed to queue paths error="permission denied" count=12444--- PASS: TestServerQueueError (0.00s)2445=== CONT TestQueueEnqueueAndFetch2446--- PASS: TestServerClientIntegration (0.00s)2447=== CONT TestDrainGivesUpWhenServerDown24482026/09/20 10:47:46 INFO Upload queue status pending=22449--- PASS: TestQueueDeduplication (0.01s)2450=== CONT TestFailedPathPrunedByLaterClosure24512026/09/20 10:47:46 INFO Uploading batch count=22452--- PASS: TestQueueEnqueueAndFetch (0.01s)2453=== CONT TestWorkerPrunesClosureDeps24542026/09/20 10:47:46 INFO Uploading batch count=224552026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=224562026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/a2457--- PASS: TestQueueFetchBatchLimit (0.01s)2458=== CONT TestDrainTimeout2459--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2460=== CONT TestWorkerSkipsGCdPaths24612026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/b2462--- PASS: TestQueueRetryMovesToBack (0.01s)2463=== CONT TestRunNotBlockedByPoisonHead24642026/09/20 10:47:46 INFO Uploading batch count=224652026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=224662026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/c2467--- PASS: TestQueueRemove (0.01s)2468=== CONT TestDrainIsolatesPoisonPath24692026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/d24702026/09/20 10:47:46 INFO Uploading batch count=224712026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=224722026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/e24732026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainGivesUpWhenServerDown3541867553/002/f24742026/09/20 10:47:46 ERROR Drain finished with paths left in queue remaining=1024752026/09/20 10:47:46 INFO Uploading batch count=124762026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=124772026/09/20 10:47:46 INFO Uploading batch count=224782026/09/20 10:47:46 INFO Upload queue status pending=224792026/09/20 10:47:46 INFO Upload queue status pending=224802026/09/20 10:47:46 INFO Uploading batch count=124812026/09/20 10:47:46 INFO Uploading batch count=124822026/09/20 10:47:46 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-5545-4069281544/TestWorkerSkipsGCdPaths3411951658/002/nonexistent24832026/09/20 10:47:46 INFO Uploading batch count=124842026/09/20 10:47:46 INFO Uploading batch count=12485--- PASS: TestDrainGivesUpWhenServerDown (0.01s)24862026/09/20 10:47:46 INFO Uploading batch count=424872026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=424882026/09/20 10:47:46 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5545-4069281544/TestDrainIsolatesPoisonPath3323431635/002/bbb24892026/09/20 10:47:46 INFO Upload queue status pending=32490--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24912026/09/20 10:47:46 INFO Uploading batch count=124922026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=124932026/09/20 10:47:46 INFO Uploading batch count=124942026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=124952026/09/20 10:47:46 INFO Uploading batch count=124962026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=124972026/09/20 10:47:46 INFO Uploading batch count=124982026/09/20 10:47:46 ERROR Upload failed error="upload failed" count=124992026/09/20 10:47:46 ERROR Drain finished with paths left in queue remaining=12500--- PASS: TestDrainIsolatesPoisonPath (0.01s)2501--- PASS: TestWorkerUploadsAndRemoves (0.03s)2502--- PASS: TestWorkerSkipsGCdPaths (0.02s)2503--- PASS: TestWorkerPrunesClosureDeps (0.03s)2504--- PASS: TestQueueRemoveLargeClosure (0.06s)2505--- PASS: TestQueueConcurrentWriters (0.15s)25062026/09/20 10:47:46 ERROR Upload failed error="context deadline exceeded" count=225072026/09/20 10:47:46 ERROR Drain finished with paths left in queue remaining=42508--- PASS: TestDrainTimeout (0.21s)25092026/09/20 10:47:47 INFO Uploading batch count=125102026/09/20 10:47:47 INFO Uploading batch count=125112026/09/20 10:47:47 INFO Uploading batch count=125122026/09/20 10:47:47 ERROR Upload failed error="upload failed" count=125132026/09/20 10:47:47 INFO Uploading batch count=125142026/09/20 10:47:47 ERROR Upload failed error="upload failed" count=125152026/09/20 10:47:47 INFO Uploading batch count=125162026/09/20 10:47:47 ERROR Upload failed error="upload failed" count=125172026/09/20 10:47:47 INFO Uploading batch count=125182026/09/20 10:47:47 ERROR Upload failed error="upload failed" count=125192026/09/20 10:47:47 ERROR Drain finished with paths left in queue remaining=12520--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2521PASS