niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #229
· 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.05s)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 TestShellSplit90=== CONT TestStaticToken91--- PASS: TestStaticToken (0.00s)92=== CONT TestFileTokenMissing93=== CONT TestScriptTokenEmptyCommand94=== CONT TestSetClientTLSDoesNotMutateDefaultTransport95=== CONT TestScriptTokenScriptFails96=== CONT TestScriptTokenBadJSON97=== CONT TestSetClientTLSErrors98=== CONT TestScriptTokenEmptyToken99=== CONT TestScriptTokenCachesUntilRefresh100=== CONT TestScriptTokenNoExpiryRerunsEveryCall101=== CONT TestFileTokenEmpty102--- PASS: TestShellSplit (0.00s)103--- PASS: TestScriptTokenEmptyCommand (0.00s)104--- PASS: TestFileTokenMissing (0.00s)105=== CONT TestFileTokenReadsAndCaches106--- PASS: TestFileTokenEmpty (0.00s)107=== RUN TestSetClientTLSErrors/missing_cert_file108=== PAUSE TestSetClientTLSErrors/missing_cert_file109=== RUN TestSetClientTLSErrors/missing_key_file110--- PASS: TestFileTokenReadsAndCaches (0.00s)111=== CONT TestStreamPushBatchesUnderLoad112=== PAUSE TestSetClientTLSErrors/missing_key_file113=== RUN TestSetClientTLSErrors/missing_ca_file114=== PAUSE TestSetClientTLSErrors/missing_ca_file115=== RUN TestSetClientTLSErrors/invalid_ca_file116=== CONT TestStreamPushGivesUpOnDeadServer117=== PAUSE TestSetClientTLSErrors/invalid_ca_file118=== CONT TestSetClientTLS119--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)120=== CONT TestStreamPushRequestLine1212026/09/20 16:24:16 ERROR Upload failed error="connection refused" count=201222026/09/20 16:24:16 ERROR Server seems unavailable, giving up on batch untried=171232026/09/20 16:24:16 ERROR Upload failed error=boom count=1124--- PASS: TestDoServerRequestAttachesToken (0.01s)125=== CONT TestConvertHashToNix32126--- PASS: TestScriptTokenScriptFails (0.01s)127=== RUN TestConvertHashToNix32/SRI_format_to_Nix32128=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32129=== RUN TestConvertHashToNix32/already_Nix32_format130=== PAUSE TestConvertHashToNix32/already_Nix32_format131=== RUN TestConvertHashToNix32/invalid_format132=== PAUSE TestConvertHashToNix32/invalid_format133=== CONT TestDoWithRetry_BodyReplayedViaGetBody134--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)135=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess136=== CONT TestResolveStorePath1372026/09/20 16:24:16 WARN Rate limiter enabled after throttle name=server-test rate=51382026/09/20 16:24:16 WARN Rate limiter enabled after throttle name=server-test rate=51392026/09/20 16:24:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:591181402026/09/20 16:24:16 WARN Rate limiter backed off name=server-test rate=51412026/09/20 16:24:16 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59118142--- PASS: TestResolveStorePath (0.00s)143=== CONT TestRateLimiterFeedback144=== RUN TestRateLimiterFeedback/429_enables_limiter145=== PAUSE TestRateLimiterFeedback/429_enables_limiter146=== RUN TestRateLimiterFeedback/503_enables_limiter147=== PAUSE TestRateLimiterFeedback/503_enables_limiter148=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter149=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter150=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter151=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter152--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)153=== CONT TestPathInfoCACompatibility154=== CONT TestParsePathInfoJSONMultiplePaths155=== RUN TestPathInfoCACompatibility/null_ca_field156=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== RUN TestSetClientTLS/rejects_connection_without_client_cert160=== RUN TestPathInfoCACompatibility/old_string_format_-_text161=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text162=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert163=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA167=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestPathInfoCACompatibility/new_structured_format_-_text170=== CONT TestParsePathInfoJSON171=== RUN TestParsePathInfoJSON/Nix_format172=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text173=== PAUSE TestParsePathInfoJSON/Nix_format174=== RUN TestParsePathInfoJSON/Lix_format175=== PAUSE TestParsePathInfoJSON/Lix_format176=== RUN TestParsePathInfoJSON/empty_input177=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method178=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method179=== PAUSE TestParsePathInfoJSON/empty_input180=== CONT TestPathInfoHashCompatibility181=== RUN TestParsePathInfoJSON/whitespace_only182=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== PAUSE TestParsePathInfoJSON/whitespace_only184=== RUN TestSetClientTLS/preserves_debug_logging_transport185=== RUN TestParsePathInfoJSON/invalid_JSON186=== PAUSE TestSetClientTLS/preserves_debug_logging_transport187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== CONT TestGetStorePathHash191=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== PAUSE TestParsePathInfoJSON/invalid_JSON193=== CONT TestDumpPathMatchesNix194=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== RUN TestGetStorePathHash/valid_store_path196=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== PAUSE TestGetStorePathHash/valid_store_path198=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error201=== CONT TestEncodeNixBase32WithRealHash202--- PASS: TestEncodeNixBase32WithRealHash (0.00s)203=== CONT TestEncodeNixBase32204=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error205=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error206=== RUN TestEncodeNixBase32/test_string_hash207=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error208=== PAUSE TestEncodeNixBase32/test_string_hash209=== RUN TestEncodeNixBase32/empty_input210=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error211=== CONT TestDumpPathWriterError212=== PAUSE TestEncodeNixBase32/empty_input213=== CONT TestDumpPathSingleFile214--- PASS: TestScriptTokenEmptyToken (0.01s)215=== CONT TestStreamPushReportsEveryPath216--- PASS: TestStreamPushReportsEveryPath (0.00s)217=== CONT TestFilterOversizedClosures218=== RUN TestFilterOversizedClosures/no_limit_keeps_everything219=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything220=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped221=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped222--- PASS: TestScriptTokenBadJSON (0.01s)223=== RUN TestFilterOversizedClosures/all_closures_skipped224=== PAUSE TestFilterOversizedClosures/all_closures_skipped225=== CONT TestUploadMultipart_SupersededByPeer226=== RUN TestUploadMultipart_SupersededByPeer/exists227=== PAUSE TestUploadMultipart_SupersededByPeer/exists228=== RUN TestUploadMultipart_SupersededByPeer/missing229=== PAUSE TestUploadMultipart_SupersededByPeer/missing230=== CONT TestPartSizeForNAR231=== CONT TestCaseHackSuffix232=== RUN TestPartSizeForNAR/zero_stays_at_minimum233=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum234=== RUN TestPartSizeForNAR/small_stays_at_minimum235=== PAUSE TestPartSizeForNAR/small_stays_at_minimum236=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum237=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum238=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts239=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts240=== RUN TestPartSizeForNAR/1_TiB241=== PAUSE TestPartSizeForNAR/1_TiB242=== RUN TestPartSizeForNAR/5_TiB_S3_max_object243=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object244=== RUN TestPartSizeForNAR/capped_at_5_GiB245=== PAUSE TestPartSizeForNAR/capped_at_5_GiB246=== CONT TestRegisterUploadedObjectReusesConnections247--- PASS: TestStreamPushRequestLine (0.02s)248=== CONT TestShellSplitErrors249--- PASS: TestShellSplitErrors (0.00s)250=== CONT TestStreamPushIsolatesFailures2512026/09/20 16:24:16 ERROR Upload failed error="bad path" count=3252--- PASS: TestStreamPushIsolatesFailures (0.00s)253=== CONT TestSetClientTLSErrors/missing_cert_file254=== CONT TestSetClientTLSErrors/invalid_ca_file255=== CONT TestSetClientTLSErrors/missing_ca_file256=== CONT TestSetClientTLSErrors/missing_key_file257=== CONT TestConvertHashToNix32/SRI_format_to_Nix32258--- PASS: TestSetClientTLSErrors (0.01s)259 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)260 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)261 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)262 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)263=== CONT TestConvertHashToNix32/invalid_format264=== CONT TestConvertHashToNix32/already_Nix32_format265--- PASS: TestConvertHashToNix32 (0.00s)266 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)267 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)268 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)269=== CONT TestRateLimiterFeedback/429_enables_limiter2702026/09/20 16:24:16 WARN Rate limiter enabled after throttle name=server-test rate=52712026/09/20 16:24:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:591882722026/09/20 16:24:16 WARN Rate limiter backed off name=server-test rate=5273=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter274=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter275=== CONT TestRateLimiterFeedback/503_enables_limiter276--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)277=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths278=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths279--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)280 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)281 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestPathInfoCACompatibility/new_structured_format_-_text284=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287--- PASS: TestPathInfoCACompatibility (0.00s)288 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)289 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)290 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)291 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)293=== CONT TestSetClientTLS/rejects_connection_without_client_cert2942026/09/20 16:24:16 WARN Rate limiter enabled after throttle name=server-test rate=52952026/09/20 16:24:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:59194296--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)297=== CONT TestSetClientTLS/preserves_debug_logging_transport2982026/09/20 16:24:16 WARN Rate limiter backed off name=server-test rate=5299--- PASS: TestRateLimiterFeedback (0.00s)300 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)301 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)302 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)303 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)304=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA305=== CONT TestParsePathInfoJSON/Nix_format306=== CONT TestParsePathInfoJSON/invalid_JSON307=== CONT TestParsePathInfoJSON/whitespace_only308=== CONT TestParsePathInfoJSON/empty_input309=== CONT TestParsePathInfoJSON/Lix_format310--- PASS: TestParsePathInfoJSON (0.00s)311 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)312 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)313 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)314 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)315 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI318=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon319=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512320--- PASS: TestPathInfoHashCompatibility (0.00s)321 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)322 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)323 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)324 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)325=== CONT TestGetStorePathHash/valid_store_path326=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error327=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error328=== CONT TestGetStorePathHash/basename_without_hyphen_should_error329--- PASS: TestGetStorePathHash (0.00s)330 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)331 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)332 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)333 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)334=== CONT TestEncodeNixBase32/test_string_hash335=== CONT TestEncodeNixBase32/empty_input336--- PASS: TestEncodeNixBase32 (0.00s)337 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)338 --- PASS: TestEncodeNixBase32/empty_input (0.00s)339=== CONT TestFilterOversizedClosures/no_limit_keeps_everything340=== CONT TestFilterOversizedClosures/all_closures_skipped3412026/09/20 16:24:16 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=50342=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3432026/09/20 16:24:16 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=2000344--- PASS: TestFilterOversizedClosures (0.00s)345 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)346 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)347 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)348=== CONT TestUploadMultipart_SupersededByPeer/exists349=== CONT TestUploadMultipart_SupersededByPeer/missing350=== CONT TestPartSizeForNAR/zero_stays_at_minimum351=== CONT TestPartSizeForNAR/1_TiB352=== CONT TestPartSizeForNAR/capped_at_5_GiB353=== CONT TestPartSizeForNAR/5_TiB_S3_max_object354=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum355=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts356=== CONT TestPartSizeForNAR/small_stays_at_minimum357--- PASS: TestPartSizeForNAR (0.00s)358 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)360 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)361 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)362 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)364 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)365--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)366 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)367 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)368--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)369--- PASS: TestDumpPathSingleFile (0.04s)370--- PASS: TestDumpPathWriterError (0.04s)371--- PASS: TestCaseHackSuffix (0.04s)3722026/09/20 16:24:16 http: TLS handshake error from 127.0.0.1:59196: remote error: tls: bad certificate373--- PASS: TestSetClientTLS (0.00s)374 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)375 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)376 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)377--- PASS: TestDumpPathMatchesNix (0.07s)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-73286-1319645990/postgres133287118/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-73286-1319645990/postgres133287118/data -l logfile start4084092026-09-20 16:24:18.366 UTC [73323] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4102026-09-20 16:24:18.366 UTC [73323] LOG: listening on Unix socket "/nix/var/nix/builds/nix-73286-1319645990/postgres133287118/.s.PGSQL.5432"4112026-09-20 16:24:18.368 UTC [73330] LOG: database system was shut down at 2026-09-20 16:24:18 UTC4122026-09-20 16:24:18.368 UTC [73331] FATAL: the database system is starting up413/nix/var/nix/builds/nix-73286-1319645990/postgres133287118:5432 - rejecting connections4142026-09-20 16:24:18.369 UTC [73323] LOG: database system is ready to accept connections415/nix/var/nix/builds/nix-73286-1319645990/postgres133287118: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 16:24:18.768 UTC [73340] ERROR: relation "goose_db_version" does not exist at character 364562026-09-20 16:24:18.768 UTC [73340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4572026/09/20 16:24:18 OK 20241026095416_initial_model.sql (20.09ms)4582026/09/20 16:24:18 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)4592026/09/20 16:24:18 OK 20251218171726_add_pins.sql (8.76ms)4602026/09/20 16:24:18 OK 20260628120000_add_object_size_and_stats.sql (11.03ms)4612026/09/20 16:24:18 OK 20260905000000_add_claims.sql (2.72ms)4622026/09/20 16:24:18 OK 20260920000000_drop_claims.sql (1.64ms)4632026/09/20 16:24:18 goose: successfully migrated database to version: 202609200000004642026/09/20 16:24:18 OK 1_commit_pending_closure.sql (2.8ms)4652026/09/20 16:24:18 OK 2_object_stats_trigger.sql (460.71µs)4662026/09/20 16:24:18 goose: up to current file version: 2467--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.49s)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.02s)566=== RUN TestWatchdogSkipsWhenUnhealthy5672026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/20 16:24:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"577--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)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 TestProxyWriteTimeout599=== CONT TestService_Rustfstest600=== CONT TestGenerateLandingPage601=== CONT TestService_AuthMiddleware602=== CONT TestResolveDBConnectionString603=== CONT TestGCTaskStore_GetEmpty604--- PASS: TestGCTaskStore_GetEmpty (0.00s)605=== CONT TestGCTaskStore_PhaseUpdates606--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)607=== CONT TestGCTaskStore_CompletedAllowsNewTask608--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)609=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT610=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle611=== RUN TestProxyWriteTimeout/narinfo612=== CONT TestSkippedUploadsHandler613=== PAUSE TestProxyWriteTimeout/narinfo614=== CONT TestParseSize615=== CONT TestGCTaskStore_Fail616=== RUN TestResolveDBConnectionString/flag_wins617--- PASS: TestGCTaskStore_Fail (0.00s)618=== CONT TestCompleteMultipartUnregistered619=== RUN TestProxyWriteTimeout/1_GiB_nar620=== PAUSE TestResolveDBConnectionString/flag_wins621=== RUN TestResolveDBConnectionString/file_when_flag_empty622=== PAUSE TestResolveDBConnectionString/file_when_flag_empty623=== RUN TestResolveDBConnectionString/missing_file_is_an_error624=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error625=== RUN TestResolveDBConnectionString/PGHOST_allows_empty626=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty627=== RUN TestResolveDBConnectionString/nothing_configured628=== PAUSE TestResolveDBConnectionString/nothing_configured629=== PAUSE TestProxyWriteTimeout/1_GiB_nar630=== CONT TestService_verifyS3Integrity631=== RUN TestProxyWriteTimeout/10_GiB_nar632=== PAUSE TestProxyWriteTimeout/10_GiB_nar633--- PASS: TestParseSize (0.00s)634=== RUN TestProxyWriteTimeout/unknown_size635=== CONT TestGracefulShutdownDrainsInflight636=== PAUSE TestProxyWriteTimeout/unknown_size637=== CONT TestService_createPendingClosureHandler6382026/09/20 16:24:19 INFO Client skipped oversized paths paths=3 nar_bytes=50000000006392026/09/20 16:24:19 INFO Starting HTTP server address=127.0.0.1:59213640--- PASS: TestSkippedUploadsHandler (0.01s)641=== CONT TestService_cleanupPendingClosuresHandler6422026/09/20 16:24:19 INFO Shutdown signal received, draining in-flight requests timeout=10s643--- PASS: TestGenerateLandingPage (0.01s)644=== CONT TestUploadHandlersRejectOversizedBody645=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure646=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure647=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart648=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart649=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts650=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts651=== CONT TestService_readinessHandler652--- PASS: TestGracefulShutdownDrainsInflight (0.08s)653=== CONT TestUploadHandlersRejectInvalidKeys654=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info655=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info656=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal657=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal658=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key659=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key660=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key661=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key662=== CONT TestIsValidUploadKey663=== RUN TestIsValidUploadKey/narinfo664=== PAUSE TestIsValidUploadKey/narinfo665=== RUN TestIsValidUploadKey/nar_zst666=== PAUSE TestIsValidUploadKey/nar_zst667=== RUN TestIsValidUploadKey/nar_xz668=== PAUSE TestIsValidUploadKey/nar_xz669=== RUN TestIsValidUploadKey/nar_plain670=== PAUSE TestIsValidUploadKey/nar_plain671=== RUN TestIsValidUploadKey/listing672=== PAUSE TestIsValidUploadKey/listing673=== RUN TestIsValidUploadKey/build_log674=== PAUSE TestIsValidUploadKey/build_log675=== RUN TestIsValidUploadKey/build_log_home-manager_file676=== PAUSE TestIsValidUploadKey/build_log_home-manager_file677=== RUN TestIsValidUploadKey/build_log_plus_in_name678=== PAUSE TestIsValidUploadKey/build_log_plus_in_name679=== RUN TestIsValidUploadKey/build_log_question_mark680=== PAUSE TestIsValidUploadKey/build_log_question_mark681=== RUN TestIsValidUploadKey/build_log_equals682=== PAUSE TestIsValidUploadKey/build_log_equals683=== RUN TestIsValidUploadKey/realisation684=== PAUSE TestIsValidUploadKey/realisation685=== RUN TestIsValidUploadKey/realisation_plus_in_output686=== PAUSE TestIsValidUploadKey/realisation_plus_in_output687=== RUN TestIsValidUploadKey/nix-cache-info688=== PAUSE TestIsValidUploadKey/nix-cache-info689=== RUN TestIsValidUploadKey/index.html690=== PAUSE TestIsValidUploadKey/index.html691=== RUN TestIsValidUploadKey/narinfo_key,_nar_type692=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type693=== RUN TestIsValidUploadKey/nar_key,_narinfo_type694=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type695=== RUN TestIsValidUploadKey/listing_key,_narinfo_type696=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type697=== RUN TestIsValidUploadKey/traversal698=== PAUSE TestIsValidUploadKey/traversal699=== RUN TestIsValidUploadKey/traversal_nar700=== PAUSE TestIsValidUploadKey/traversal_nar701=== RUN TestIsValidUploadKey/absolute702=== PAUSE TestIsValidUploadKey/absolute703=== RUN TestIsValidUploadKey/empty_key704=== PAUSE TestIsValidUploadKey/empty_key705=== RUN TestIsValidUploadKey/unknown_type706=== PAUSE TestIsValidUploadKey/unknown_type707=== CONT TestReadProxyNarStreaming7082026-09-20 16:24:19.609 UTC [73425] ERROR: relation "goose_db_version" does not exist at character 367092026-09-20 16:24:19.609 UTC [73425] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026-09-20 16:24:19.616 UTC [73426] ERROR: relation "goose_db_version" does not exist at character 367112026-09-20 16:24:19.616 UTC [73426] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-09-20 16:24:19.617 UTC [73427] ERROR: relation "goose_db_version" does not exist at character 367132026-09-20 16:24:19.617 UTC [73427] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-09-20 16:24:19.617 UTC [73428] ERROR: relation "goose_db_version" does not exist at character 367152026-09-20 16:24:19.617 UTC [73428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-09-20 16:24:19.618 UTC [73429] ERROR: relation "goose_db_version" does not exist at character 367172026-09-20 16:24:19.618 UTC [73429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026-09-20 16:24:19.619 UTC [73431] ERROR: relation "goose_db_version" does not exist at character 367192026-09-20 16:24:19.619 UTC [73431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-09-20 16:24:19.619 UTC [73432] ERROR: relation "goose_db_version" does not exist at character 367212026-09-20 16:24:19.619 UTC [73432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-20 16:24:19.621 UTC [73430] ERROR: relation "goose_db_version" does not exist at character 367232026-09-20 16:24:19.621 UTC [73430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-20 16:24:19.622 UTC [73433] ERROR: relation "goose_db_version" does not exist at character 367252026-09-20 16:24:19.622 UTC [73433] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-09-20 16:24:19.622 UTC [73434] ERROR: relation "goose_db_version" does not exist at character 367272026-09-20 16:24:19.622 UTC [73434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026/09/20 16:24:19 OK 20241026095416_initial_model.sql (10.5ms)7292026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.87ms)7302026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (867.08µs)7312026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.14ms)7322026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)7332026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (490.17µs)7342026/09/20 16:24:19 OK 20241026095416_initial_model.sql (8.35ms)7352026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.47ms)7362026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.44ms)7372026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.41ms)7382026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (665.46µs)7392026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.58ms)7402026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (533.92µs)7412026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (834.33µs)7422026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.6ms)7432026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (830.17µs)7442026/09/20 16:24:19 OK 20251218171726_add_pins.sql (2.05ms)7452026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)7462026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.65ms)7472026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.5ms)7482026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.37ms)7492026/09/20 16:24:19 OK 20241026095416_initial_model.sql (8.93ms)7502026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.58ms)7512026/09/20 16:24:19 OK 20251218171726_add_pins.sql (2.19ms)7522026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (717.29µs)7532026/09/20 16:24:19 OK 20260905000000_add_claims.sql (2ms)7542026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (2.14ms)7552026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)7562026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)7572026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.68ms)7582026/09/20 16:24:19 OK 20241026095416_initial_model.sql (7.94ms)7592026/09/20 16:24:19 OK 20260905000000_add_claims.sql (2.13ms)7602026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (1.15ms)7612026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007622026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)7632026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.92ms)7642026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (847.83µs)7652026/09/20 16:24:19 OK 20251210153512_drop_unused_gin_index.sql (663.67µs)7662026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.77ms)7672026/09/20 16:24:19 OK 20260905000000_add_claims.sql (1.47ms)7682026/09/20 16:24:19 OK 20260905000000_add_claims.sql (2.29ms)7692026/09/20 16:24:19 OK 1_commit_pending_closure.sql (1.29ms)7702026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (1.52ms)7712026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007722026/09/20 16:24:19 OK 20260905000000_add_claims.sql (2.54ms)7732026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.41ms)7742026/09/20 16:24:19 OK 20251218171726_add_pins.sql (1.5ms)7752026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (1.23ms)7762026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007772026/09/20 16:24:19 OK 2_object_stats_trigger.sql (490.63µs)7782026/09/20 16:24:19 goose: up to current file version: 27792026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (992.42µs)7802026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007812026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.85ms)7822026/09/20 16:24:19 OK 1_commit_pending_closure.sql (1.13ms)7832026/09/20 16:24:19 OK 20260905000000_add_claims.sql (2.54ms)7842026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (1.31ms)7852026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007862026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.26ms)7872026/09/20 16:24:19 OK 20260628120000_add_object_size_and_stats.sql (1.56ms)7882026/09/20 16:24:19 OK 2_object_stats_trigger.sql (246.5µs)7892026/09/20 16:24:19 goose: up to current file version: 27902026/09/20 16:24:19 OK 1_commit_pending_closure.sql (1.51ms)7912026/09/20 16:24:19 OK 1_commit_pending_closure.sql (1.38ms)7922026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (998.92µs)7932026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000007942026/09/20 16:24:19 OK 20260905000000_add_claims.sql (3.59ms)7952026/09/20 16:24:19 OK 20260905000000_add_claims.sql (1.5ms)7962026/09/20 16:24:19 OK 2_object_stats_trigger.sql (450.58µs)7972026/09/20 16:24:19 goose: up to current file version: 27982026/09/20 16:24:19 OK 2_object_stats_trigger.sql (555.67µs)7992026/09/20 16:24:19 goose: up to current file version: 28002026/09/20 16:24:19 OK 20260905000000_add_claims.sql (1.42ms)8012026/09/20 16:24:19 OK 1_commit_pending_closure.sql (772.13µs)8022026/09/20 16:24:19 OK 1_commit_pending_closure.sql (1.6ms)8032026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (792.75µs)8042026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000008052026/09/20 16:24:19 OK 20260905000000_add_claims.sql (1.38ms)8062026/09/20 16:24:19 OK 2_object_stats_trigger.sql (310.58µs)8072026/09/20 16:24:19 goose: up to current file version: 28082026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (1.05ms)8092026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000008102026/09/20 16:24:19 OK 2_object_stats_trigger.sql (367µs)8112026/09/20 16:24:19 goose: up to current file version: 28122026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (674.25µs)8132026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000008142026/09/20 16:24:19 OK 1_commit_pending_closure.sql (724.92µs)8152026/09/20 16:24:19 OK 20260920000000_drop_claims.sql (718.29µs)8162026/09/20 16:24:19 goose: successfully migrated database to version: 202609200000008172026/09/20 16:24:19 OK 2_object_stats_trigger.sql (207.96µs)8182026/09/20 16:24:19 goose: up to current file version: 28192026/09/20 16:24:19 OK 1_commit_pending_closure.sql (719.21µs)8202026/09/20 16:24:19 OK 1_commit_pending_closure.sql (646.29µs)8212026/09/20 16:24:19 OK 2_object_stats_trigger.sql (181.21µs)8222026/09/20 16:24:19 goose: up to current file version: 28232026/09/20 16:24:19 OK 2_object_stats_trigger.sql (161.13µs)8242026/09/20 16:24:19 goose: up to current file version: 28252026/09/20 16:24:19 OK 1_commit_pending_closure.sql (647.83µs)8262026/09/20 16:24:19 OK 2_object_stats_trigger.sql (176.5µs)8272026/09/20 16:24:19 goose: up to current file version: 2828--- PASS: TestService_Rustfstest (0.41s)829=== CONT TestPresignedUploadRegisteredBeforeCommit8302026/09/20 16:24:19 INFO Received cleanup request method=DELETE path=/api/pending_closures8312026/09/20 16:24:19 INFO Aborted multipart uploads count=08322026/09/20 16:24:19 INFO Received uploads request method=POST path=/api/pending_closures8332026/09/20 16:24:19 INFO Received cleanup request method=DELETE path=/api/pending_closures8342026/09/20 16:24:19 INFO Aborted multipart uploads count=18352026/09/20 16:24:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8362026-09-20 16:24:19.919 UTC [73428] ERROR: Closure does not exist: id=18372026-09-20 16:24:19.919 UTC [73428] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8382026-09-20 16:24:19.919 UTC [73428] STATEMENT: -- name: CommitPendingClosure :exec839 SELECT commit_pending_closure($1::bigint)840 841--- PASS: TestService_cleanupPendingClosuresHandler (0.59s)842=== CONT TestObjectStatsTrigger8432026/09/20 16:24:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8442026/09/20 16:24:20 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst845--- PASS: TestCompleteMultipartUnregistered (0.72s)846=== CONT TestCompletedNarNotReofferedAcrossClosures8472026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures8482026-09-20 16:24:20.293 UTC [73441] ERROR: relation "goose_db_version" does not exist at character 368492026-09-20 16:24:20.293 UTC [73441] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures8512026/09/20 16:24:20 OK 20241026095416_initial_model.sql (72.16ms)8522026/09/20 16:24:20 OK 20251210153512_drop_unused_gin_index.sql (14.39ms)8532026/09/20 16:24:20 OK 20251218171726_add_pins.sql (44.42ms)8542026/09/20 16:24:20 OK 20260628120000_add_object_size_and_stats.sql (27.66ms)8552026-09-20 16:24:20.542 UTC [73443] ERROR: relation "goose_db_version" does not exist at character 368562026-09-20 16:24:20.542 UTC [73443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8572026/09/20 16:24:20 OK 20260905000000_add_claims.sql (42.77ms)8582026/09/20 16:24:20 OK 20260920000000_drop_claims.sql (35.26ms)8592026/09/20 16:24:20 goose: successfully migrated database to version: 202609200000008602026/09/20 16:24:20 OK 1_commit_pending_closure.sql (2.56ms)8612026/09/20 16:24:20 OK 2_object_stats_trigger.sql (532.5µs)8622026/09/20 16:24:20 goose: up to current file version: 28632026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures8642026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures8652026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures8662026/09/20 16:24:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8672026/09/20 16:24:20 OK 20241026095416_initial_model.sql (99.91ms)8682026/09/20 16:24:20 OK 20251210153512_drop_unused_gin_index.sql (12.76ms)8692026/09/20 16:24:20 OK 20251218171726_add_pins.sql (21.62ms)8702026/09/20 16:24:20 OK 20260628120000_add_object_size_and_stats.sql (24.3ms)8712026/09/20 16:24:20 OK 20260905000000_add_claims.sql (36.32ms)8722026/09/20 16:24:20 OK 20260920000000_drop_claims.sql (32.73ms)8732026/09/20 16:24:20 goose: successfully migrated database to version: 202609200000008742026/09/20 16:24:20 OK 1_commit_pending_closure.sql (2.66ms)8752026/09/20 16:24:20 OK 2_object_stats_trigger.sql (530.33µs)8762026/09/20 16:24:20 goose: up to current file version: 28772026/09/20 16:24:20 INFO Received uploads request method=POST path=/api/pending_closures878--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.58s)879=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8802026-09-20 16:24:20.939 UTC [73451] ERROR: relation "goose_db_version" does not exist at character 368812026-09-20 16:24:20.939 UTC [73451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8822026/09/20 16:24:21 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"883--- PASS: TestService_AuthMiddleware (1.76s)884=== CONT TestReadProxyNarinfoAlreadyDecompressed8852026/09/20 16:24:21 OK 20241026095416_initial_model.sql (115.01ms)8862026/09/20 16:24:21 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)8872026/09/20 16:24:21 OK 20251218171726_add_pins.sql (6.75ms)8882026/09/20 16:24:21 OK 20260628120000_add_object_size_and_stats.sql (6.23ms)8892026/09/20 16:24:21 OK 20260905000000_add_claims.sql (44.69ms)8902026/09/20 16:24:21 OK 20260920000000_drop_claims.sql (23.73ms)8912026/09/20 16:24:21 goose: successfully migrated database to version: 202609200000008922026/09/20 16:24:21 OK 1_commit_pending_closure.sql (880.08µs)8932026/09/20 16:24:21 OK 2_object_stats_trigger.sql (218.54µs)8942026/09/20 16:24:21 goose: up to current file version: 28952026/09/20 16:24:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete896--- PASS: TestReadProxyNarStreaming (1.90s)897=== CONT TestRedundantMultipartUpload8982026/09/20 16:24:21 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLjdhYmMzOWUwLWY3ZGMtNDkxOS1iMTk5LWVlZGZmZmU4NjNmZngxNzg5OTIxNDYwMTkzNDAxMDAw parts=108992026/09/20 16:24:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9002026/09/20 16:24:21 INFO Completed upload id=19012026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures9022026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures9032026/09/20 16:24:21 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9042026/09/20 16:24:21 WARN Found objects in DB but missing from S3, will re-upload count=1905--- PASS: TestService_verifyS3Integrity (2.05s)906=== CONT TestReadProxyNarinfo9072026/09/20 16:24:21 WARN readiness check failed error="closed pool"908--- PASS: TestService_readinessHandler (2.09s)909=== CONT TestReadRedirectUsesPublicS3URL9102026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures9112026/09/20 16:24:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9122026-09-20 16:24:21.662 UTC [73479] ERROR: relation "goose_db_version" does not exist at character 369132026-09-20 16:24:21.662 UTC [73479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9142026/09/20 16:24:21 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLmQ5MjQ4ODhjLTA1NWUtNGViNy05ZmNkLWRiYzgzOTllMjA3N3gxNzg5OTIxNDYwNjEyOTg4MDAw parts=109152026/09/20 16:24:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9162026/09/20 16:24:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9172026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures9182026/09/20 16:24:21 INFO Completed upload id=19192026/09/20 16:24:21 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000920--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.99s)921=== CONT TestIsValidCachePath922=== RUN TestIsValidCachePath/narinfo923=== PAUSE TestIsValidCachePath/narinfo924=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars925=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars926=== RUN TestIsValidCachePath/nar_zst927=== PAUSE TestIsValidCachePath/nar_zst928=== RUN TestIsValidCachePath/nar_xz929=== PAUSE TestIsValidCachePath/nar_xz930=== RUN TestIsValidCachePath/nar_bz2931=== PAUSE TestIsValidCachePath/nar_bz2932=== RUN TestIsValidCachePath/nar_uncompressed933=== PAUSE TestIsValidCachePath/nar_uncompressed934=== RUN TestIsValidCachePath/ls935=== PAUSE TestIsValidCachePath/ls936=== RUN TestIsValidCachePath/log937=== PAUSE TestIsValidCachePath/log938=== RUN TestIsValidCachePath/realisation939=== PAUSE TestIsValidCachePath/realisation940=== RUN TestIsValidCachePath/nix-cache-info941=== PAUSE TestIsValidCachePath/nix-cache-info942=== RUN TestIsValidCachePath/index.html943=== PAUSE TestIsValidCachePath/index.html944=== RUN TestIsValidCachePath/traversal_parent945=== PAUSE TestIsValidCachePath/traversal_parent946=== RUN TestIsValidCachePath/traversal_in_middle947=== PAUSE TestIsValidCachePath/traversal_in_middle948=== RUN TestIsValidCachePath/invalid_char_e949=== PAUSE TestIsValidCachePath/invalid_char_e950=== RUN TestIsValidCachePath/invalid_char_u951=== PAUSE TestIsValidCachePath/invalid_char_u952=== RUN TestIsValidCachePath/random_path953=== PAUSE TestIsValidCachePath/random_path954=== RUN TestIsValidCachePath/empty955=== PAUSE TestIsValidCachePath/empty956=== RUN TestIsValidCachePath/leading_slash957=== PAUSE TestIsValidCachePath/leading_slash958=== RUN TestIsValidCachePath/wrong_extension959=== PAUSE TestIsValidCachePath/wrong_extension960=== RUN TestIsValidCachePath/short_hash961=== PAUSE TestIsValidCachePath/short_hash962=== CONT TestReadProxyRangeRequest9632026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures9642026/09/20 16:24:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures9652026/09/20 16:24:21 INFO Aborted multipart uploads count=09662026-09-20 16:24:21.726 UTC [73482] ERROR: relation "goose_db_version" does not exist at character 369672026-09-20 16:24:21.726 UTC [73482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9682026/09/20 16:24:21 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=09692026/09/20 16:24:21 INFO Vacuumed table table=pending_closures9702026/09/20 16:24:21 INFO Vacuumed table table=pending_objects9712026/09/20 16:24:21 INFO Vacuumed table table=multipart_uploads9722026/09/20 16:24:21 OK 20241026095416_initial_model.sql (68.03ms)9732026/09/20 16:24:21 OK 20251210153512_drop_unused_gin_index.sql (5.75ms)9742026/09/20 16:24:21 INFO Vacuumed table table=closures9752026/09/20 16:24:21 OK 20251218171726_add_pins.sql (10.23ms)9762026/09/20 16:24:21 INFO Vacuumed table table=objects9772026/09/20 16:24:21 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000978--- PASS: TestService_createPendingClosureHandler (2.50s)979=== CONT TestParseSingleRange980=== RUN TestParseSingleRange/none981=== PAUSE TestParseSingleRange/none982=== RUN TestParseSingleRange/unknown_unit983=== PAUSE TestParseSingleRange/unknown_unit984=== RUN TestParseSingleRange/multi-range_ignored985=== PAUSE TestParseSingleRange/multi-range_ignored986=== RUN TestParseSingleRange/malformed_no_dash987=== PAUSE TestParseSingleRange/malformed_no_dash988=== RUN TestParseSingleRange/malformed_both_empty989=== PAUSE TestParseSingleRange/malformed_both_empty990=== RUN TestParseSingleRange/malformed_end_before_start991=== PAUSE TestParseSingleRange/malformed_end_before_start992=== RUN TestParseSingleRange/closed993=== PAUSE TestParseSingleRange/closed994=== RUN TestParseSingleRange/open-ended995=== PAUSE TestParseSingleRange/open-ended996=== RUN TestParseSingleRange/end_clamped_to_size997=== PAUSE TestParseSingleRange/end_clamped_to_size998=== RUN TestParseSingleRange/suffix999=== PAUSE TestParseSingleRange/suffix1000=== RUN TestParseSingleRange/suffix_exceeds_size1001=== PAUSE TestParseSingleRange/suffix_exceeds_size1002=== RUN TestParseSingleRange/single_byte1003=== PAUSE TestParseSingleRange/single_byte1004=== RUN TestParseSingleRange/start_past_EOF1005=== PAUSE TestParseSingleRange/start_past_EOF1006=== RUN TestParseSingleRange/start_far_past_EOF1007=== PAUSE TestParseSingleRange/start_far_past_EOF1008=== CONT TestReadRedirectKeepsNarinfoProxied10092026/09/20 16:24:21 OK 20260628120000_add_object_size_and_stats.sql (28.73ms)10102026/09/20 16:24:21 OK 20241026095416_initial_model.sql (73.22ms)10112026/09/20 16:24:21 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)10122026/09/20 16:24:21 OK 20260905000000_add_claims.sql (7.23ms)10132026/09/20 16:24:21 OK 20260920000000_drop_claims.sql (8.34ms)10142026/09/20 16:24:21 goose: successfully migrated database to version: 2026092000000010152026/09/20 16:24:21 OK 1_commit_pending_closure.sql (2.03ms)10162026/09/20 16:24:21 OK 2_object_stats_trigger.sql (390.38µs)10172026/09/20 16:24:21 goose: up to current file version: 210182026/09/20 16:24:21 OK 20251218171726_add_pins.sql (17.77ms)1019--- PASS: TestObjectStatsTrigger (1.94s)1020=== CONT TestReadRedirectNar10212026/09/20 16:24:21 OK 20260628120000_add_object_size_and_stats.sql (18.42ms)10222026/09/20 16:24:21 OK 20260905000000_add_claims.sql (13.97ms)10232026/09/20 16:24:21 OK 20260920000000_drop_claims.sql (12.41ms)10242026/09/20 16:24:21 goose: successfully migrated database to version: 2026092000000010252026/09/20 16:24:21 OK 1_commit_pending_closure.sql (2.46ms)10262026/09/20 16:24:21 OK 2_object_stats_trigger.sql (556.25µs)10272026/09/20 16:24:21 goose: up to current file version: 210282026/09/20 16:24:21 INFO Received uploads request method=POST path=/api/pending_closures10292026/09/20 16:24:22 INFO Received uploads request method=POST path=/api/pending_closures10302026/09/20 16:24:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/09/20 16:24:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLjBkY2JmODJmLTFjMGEtNDFmMC05OTE2LTViMDZhZjI4ZWU5N3gxNzg5OTIxNDYyMTgzOTU4MDAw1032--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.29s)1033=== CONT TestResurrectedObjectNotDeleted10342026/09/20 16:24:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLjBkY2JmODJmLTFjMGEtNDFmMC05OTE2LTViMDZhZjI4ZWU5N3gxNzg5OTIxNDYyMTgzOTU4MDAw parts=11035--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.48s)1036=== CONT TestReadProxyDisabled10372026-09-20 16:24:22.398 UTC [73502] ERROR: relation "goose_db_version" does not exist at character 3610382026-09-20 16:24:22.398 UTC [73502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10392026-09-20 16:24:22.400 UTC [73503] ERROR: relation "goose_db_version" does not exist at character 3610402026-09-20 16:24:22.400 UTC [73503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10412026-09-20 16:24:22.403 UTC [73504] ERROR: relation "goose_db_version" does not exist at character 3610422026-09-20 16:24:22.403 UTC [73504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10432026/09/20 16:24:22 OK 20241026095416_initial_model.sql (20.44ms)10442026/09/20 16:24:22 OK 20241026095416_initial_model.sql (19.88ms)10452026/09/20 16:24:22 OK 20241026095416_initial_model.sql (20.27ms)10462026/09/20 16:24:22 OK 20251210153512_drop_unused_gin_index.sql (828.75µs)10472026/09/20 16:24:22 OK 20251210153512_drop_unused_gin_index.sql (467.38µs)10482026/09/20 16:24:22 OK 20251210153512_drop_unused_gin_index.sql (440.08µs)10492026/09/20 16:24:22 OK 20251218171726_add_pins.sql (824.46µs)10502026/09/20 16:24:22 OK 20251218171726_add_pins.sql (977.38µs)10512026/09/20 16:24:22 OK 20251218171726_add_pins.sql (1.24ms)10522026/09/20 16:24:22 OK 20260628120000_add_object_size_and_stats.sql (15.89ms)10532026/09/20 16:24:22 OK 20260628120000_add_object_size_and_stats.sql (22.89ms)10542026/09/20 16:24:22 OK 20260628120000_add_object_size_and_stats.sql (23.23ms)10552026/09/20 16:24:22 OK 20260905000000_add_claims.sql (18.54ms)10562026/09/20 16:24:22 OK 20260905000000_add_claims.sql (12.7ms)10572026/09/20 16:24:22 OK 20260920000000_drop_claims.sql (8.31ms)10582026/09/20 16:24:22 goose: successfully migrated database to version: 2026092000000010592026/09/20 16:24:22 OK 20260905000000_add_claims.sql (20.35ms)10602026/09/20 16:24:22 OK 1_commit_pending_closure.sql (1.21ms)10612026/09/20 16:24:22 OK 2_object_stats_trigger.sql (218.58µs)10622026/09/20 16:24:22 goose: up to current file version: 210632026/09/20 16:24:22 OK 20260920000000_drop_claims.sql (14.52ms)10642026/09/20 16:24:22 goose: successfully migrated database to version: 2026092000000010652026/09/20 16:24:22 OK 1_commit_pending_closure.sql (1.11ms)10662026/09/20 16:24:22 OK 2_object_stats_trigger.sql (260.38µs)10672026/09/20 16:24:22 goose: up to current file version: 210682026/09/20 16:24:22 OK 20260920000000_drop_claims.sql (14.04ms)10692026/09/20 16:24:22 goose: successfully migrated database to version: 2026092000000010702026/09/20 16:24:22 OK 1_commit_pending_closure.sql (838µs)10712026/09/20 16:24:22 OK 2_object_stats_trigger.sql (224.33µs)10722026/09/20 16:24:22 goose: up to current file version: 210732026/09/20 16:24:22 INFO Received uploads request method=POST path=/api/pending_closures10742026/09/20 16:24:22 INFO Received uploads request method=POST path=/api/pending_closures1075--- PASS: TestReadProxyNarinfo (1.53s)1076=== CONT TestOrphanedObjectsGCStressTest10772026-09-20 16:24:22.970 UTC [73511] ERROR: relation "goose_db_version" does not exist at character 3610782026-09-20 16:24:22.970 UTC [73511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026/09/20 16:24:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1080--- PASS: TestReadRedirectUsesPublicS3URL (1.72s)1081=== CONT TestReadProxyRootRedirectsToIndexHTML10822026/09/20 16:24:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLmRkMjk2MjQ1LWMxZjMtNGY1MS1iNGJjLThmNDkxZTk2ZmIxM3gxNzg5OTIxNDYxOTc3NTI2MDAw parts=1210832026/09/20 16:24:23 INFO Received uploads request method=POST path=/api/pending_closures1084--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.16s)1085=== CONT TestOrphanedObjectsGC10862026-09-20 16:24:23.220 UTC [73515] ERROR: relation "goose_db_version" does not exist at character 3610872026-09-20 16:24:23.220 UTC [73515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026/09/20 16:24:23 OK 20241026095416_initial_model.sql (135.86ms)10892026/09/20 16:24:23 OK 20251210153512_drop_unused_gin_index.sql (745.42µs)10902026/09/20 16:24:23 OK 20251218171726_add_pins.sql (926µs)10912026-09-20 16:24:23.225 UTC [73518] ERROR: relation "goose_db_version" does not exist at character 3610922026-09-20 16:24:23.225 UTC [73518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026/09/20 16:24:23 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)10942026/09/20 16:24:23 OK 20260905000000_add_claims.sql (9.11ms)10952026/09/20 16:24:23 OK 20260920000000_drop_claims.sql (17.52ms)10962026/09/20 16:24:23 goose: successfully migrated database to version: 2026092000000010972026/09/20 16:24:23 OK 1_commit_pending_closure.sql (1.22ms)10982026/09/20 16:24:23 OK 2_object_stats_trigger.sql (220.17µs)10992026/09/20 16:24:23 goose: up to current file version: 211002026/09/20 16:24:23 OK 20241026095416_initial_model.sql (99.09ms)11012026/09/20 16:24:23 OK 20241026095416_initial_model.sql (90.86ms)11022026/09/20 16:24:23 OK 20251210153512_drop_unused_gin_index.sql (13.09ms)11032026/09/20 16:24:23 OK 20251210153512_drop_unused_gin_index.sql (6.29ms)11042026/09/20 16:24:23 OK 20251218171726_add_pins.sql (23.16ms)11052026/09/20 16:24:23 OK 20251218171726_add_pins.sql (17.69ms)11062026/09/20 16:24:23 OK 20260628120000_add_object_size_and_stats.sql (12.58ms)11072026/09/20 16:24:23 OK 20260628120000_add_object_size_and_stats.sql (18.42ms)11082026/09/20 16:24:23 OK 20260905000000_add_claims.sql (25.38ms)11092026/09/20 16:24:23 OK 20260905000000_add_claims.sql (30.54ms)11102026/09/20 16:24:23 OK 20260920000000_drop_claims.sql (20.68ms)11112026/09/20 16:24:23 goose: successfully migrated database to version: 2026092000000011122026/09/20 16:24:23 OK 1_commit_pending_closure.sql (865.67µs)11132026/09/20 16:24:23 OK 2_object_stats_trigger.sql (251.17µs)11142026/09/20 16:24:23 goose: up to current file version: 211152026/09/20 16:24:23 OK 20260920000000_drop_claims.sql (32.8ms)11162026/09/20 16:24:23 goose: successfully migrated database to version: 2026092000000011172026/09/20 16:24:23 OK 1_commit_pending_closure.sql (756.46µs)11182026/09/20 16:24:23 OK 2_object_stats_trigger.sql (201.13µs)11192026/09/20 16:24:23 goose: up to current file version: 21120--- PASS: TestReadProxyRangeRequest (1.76s)1121=== CONT TestReadProxyConditionalGet11222026-09-20 16:24:23.580 UTC [73523] ERROR: relation "goose_db_version" does not exist at character 3611232026-09-20 16:24:23.580 UTC [73523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11242026-09-20 16:24:23.592 UTC [73524] ERROR: relation "goose_db_version" does not exist at character 3611252026-09-20 16:24:23.592 UTC [73524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1126--- PASS: TestReadRedirectKeepsNarinfoProxied (1.86s)1127=== CONT TestCacheStatsHandler11282026/09/20 16:24:23 OK 20241026095416_initial_model.sql (80.19ms)11292026/09/20 16:24:23 OK 20241026095416_initial_model.sql (97.47ms)11302026/09/20 16:24:23 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)11312026/09/20 16:24:23 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)11322026/09/20 16:24:23 OK 20251218171726_add_pins.sql (6.55ms)11332026/09/20 16:24:23 OK 20251218171726_add_pins.sql (13.17ms)11342026/09/20 16:24:23 OK 20260628120000_add_object_size_and_stats.sql (8.54ms)11352026/09/20 16:24:23 OK 20260628120000_add_object_size_and_stats.sql (16.38ms)11362026/09/20 16:24:23 OK 20260905000000_add_claims.sql (87.32ms)11372026/09/20 16:24:23 OK 20260905000000_add_claims.sql (73.85ms)11382026/09/20 16:24:23 OK 20260920000000_drop_claims.sql (17.92ms)11392026/09/20 16:24:23 goose: successfully migrated database to version: 2026092000000011402026/09/20 16:24:23 OK 1_commit_pending_closure.sql (1.01ms)11412026/09/20 16:24:23 OK 2_object_stats_trigger.sql (224.33µs)11422026/09/20 16:24:23 goose: up to current file version: 211432026/09/20 16:24:23 OK 20260920000000_drop_claims.sql (27.74ms)11442026/09/20 16:24:23 goose: successfully migrated database to version: 2026092000000011452026/09/20 16:24:23 OK 1_commit_pending_closure.sql (1.14ms)11462026/09/20 16:24:23 OK 2_object_stats_trigger.sql (217.5µs)11472026/09/20 16:24:23 goose: up to current file version: 21148--- PASS: TestReadRedirectNar (2.04s)1149=== CONT TestReadProxyHead11502026/09/20 16:24:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11512026/09/20 16:24:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzE2MGM0MGEtYTRiMi00ZWE4LTg0NzItMmQ5NmJhMmQ1Y2UzLmYzZjY4Nzg3LTcxMWEtNGYxYy05MmYzLTM1N2RhYWFiZmIzZHgxNzg5OTIxNDYyNjg3ODM4MDAw parts=121152--- PASS: TestRedundantMultipartUpload (2.67s)1153=== CONT TestPinProtectsFromGC11542026-09-20 16:24:24.018 UTC [73531] ERROR: relation "goose_db_version" does not exist at character 3611552026-09-20 16:24:24.018 UTC [73531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1156--- PASS: TestReadProxyDisabled (1.70s)1157=== CONT TestReadProxyInvalidPath11582026/09/20 16:24:24 OK 20241026095416_initial_model.sql (51.53ms)11592026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (5.79ms)11602026/09/20 16:24:24 OK 20251218171726_add_pins.sql (7.62ms)11612026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)11622026-09-20 16:24:24.127 UTC [73534] ERROR: relation "goose_db_version" does not exist at character 3611632026-09-20 16:24:24.127 UTC [73534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026/09/20 16:24:24 OK 20260905000000_add_claims.sql (21.06ms)11652026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (14.9ms)11662026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000011672026/09/20 16:24:24 OK 1_commit_pending_closure.sql (1.52ms)11682026/09/20 16:24:24 OK 2_object_stats_trigger.sql (234.5µs)11692026/09/20 16:24:24 goose: up to current file version: 211702026/09/20 16:24:24 OK 20241026095416_initial_model.sql (55.14ms)11712026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (10.25ms)11722026/09/20 16:24:24 OK 20251218171726_add_pins.sql (13.76ms)11732026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (13.22ms)11742026-09-20 16:24:24.237 UTC [73535] ERROR: relation "goose_db_version" does not exist at character 3611752026-09-20 16:24:24.237 UTC [73535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11762026/09/20 16:24:24 OK 20260905000000_add_claims.sql (14.02ms)11772026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (8.83ms)11782026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000011792026/09/20 16:24:24 OK 1_commit_pending_closure.sql (1.08ms)11802026/09/20 16:24:24 OK 2_object_stats_trigger.sql (201.17µs)11812026/09/20 16:24:24 goose: up to current file version: 21182--- PASS: TestResurrectedObjectNotDeleted (1.91s)1183=== CONT TestClientSharedPathCommittedMidPush11842026/09/20 16:24:24 OK 20241026095416_initial_model.sql (49.12ms)11852026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (17.58ms)11862026/09/20 16:24:24 OK 20251218171726_add_pins.sql (7.68ms)11872026-09-20 16:24:24.327 UTC [73538] ERROR: relation "goose_db_version" does not exist at character 3611882026-09-20 16:24:24.327 UTC [73538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (12.77ms)11902026/09/20 16:24:24 OK 20260905000000_add_claims.sql (17.43ms)11912026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (14.46ms)11922026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000011932026/09/20 16:24:24 OK 1_commit_pending_closure.sql (960.79µs)11942026/09/20 16:24:24 OK 2_object_stats_trigger.sql (268.13µs)11952026/09/20 16:24:24 goose: up to current file version: 211962026/09/20 16:24:24 OK 20241026095416_initial_model.sql (66.82ms)11972026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (431.25µs)11982026/09/20 16:24:24 OK 20251218171726_add_pins.sql (11.05ms)11992026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)12002026/09/20 16:24:24 OK 20260905000000_add_claims.sql (21.96ms)12012026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (1.74ms)12022026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000012032026/09/20 16:24:24 OK 1_commit_pending_closure.sql (910.58µs)12042026/09/20 16:24:24 OK 2_object_stats_trigger.sql (227.04µs)12052026/09/20 16:24:24 goose: up to current file version: 212062026-09-20 16:24:24.538 UTC [73539] ERROR: relation "goose_db_version" does not exist at character 3612072026-09-20 16:24:24.538 UTC [73539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1208--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.37s)1209=== CONT TestReadProxy40412102026/09/20 16:24:24 OK 20241026095416_initial_model.sql (54.7ms)12112026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)12122026/09/20 16:24:24 OK 20251218171726_add_pins.sql (12.26ms)12132026-09-20 16:24:24.630 UTC [73542] ERROR: relation "goose_db_version" does not exist at character 3612142026-09-20 16:24:24.630 UTC [73542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12152026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (15.71ms)12162026/09/20 16:24:24 OK 20260905000000_add_claims.sql (30.49ms)12172026-09-20 16:24:24.678 UTC [73543] ERROR: relation "goose_db_version" does not exist at character 3612182026-09-20 16:24:24.678 UTC [73543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (19.9ms)12202026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000012212026/09/20 16:24:24 OK 1_commit_pending_closure.sql (1.05ms)12222026/09/20 16:24:24 OK 2_object_stats_trigger.sql (228.08µs)12232026/09/20 16:24:24 goose: up to current file version: 212242026/09/20 16:24:24 OK 20241026095416_initial_model.sql (72.77ms)12252026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)12262026/09/20 16:24:24 OK 20251218171726_add_pins.sql (29.79ms)12272026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (22.7ms)12282026/09/20 16:24:24 OK 20241026095416_initial_model.sql (100.18ms)12292026/09/20 16:24:24 OK 20251210153512_drop_unused_gin_index.sql (5.82ms)12302026/09/20 16:24:24 OK 20260905000000_add_claims.sql (40.29ms)12312026/09/20 16:24:24 OK 20251218171726_add_pins.sql (10.34ms)12322026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (11.79ms)12332026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000012342026/09/20 16:24:24 OK 1_commit_pending_closure.sql (2.25ms)12352026/09/20 16:24:24 OK 2_object_stats_trigger.sql (289.21µs)12362026/09/20 16:24:24 goose: up to current file version: 212372026/09/20 16:24:24 OK 20260628120000_add_object_size_and_stats.sql (23.07ms)12382026/09/20 16:24:24 OK 20260905000000_add_claims.sql (48.92ms)12392026/09/20 16:24:24 OK 20260920000000_drop_claims.sql (23.58ms)12402026/09/20 16:24:24 goose: successfully migrated database to version: 2026092000000012412026/09/20 16:24:24 OK 1_commit_pending_closure.sql (1.59ms)12422026/09/20 16:24:24 OK 2_object_stats_trigger.sql (342.46µs)12432026/09/20 16:24:24 goose: up to current file version: 21244--- PASS: TestReadProxyConditionalGet (1.49s)1245=== CONT TestClientWithDependencies12462026-09-20 16:24:24.999 UTC [73546] ERROR: relation "goose_db_version" does not exist at character 3612472026-09-20 16:24:24.999 UTC [73546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026/09/20 16:24:25 OK 20241026095416_initial_model.sql (171.13ms)12492026/09/20 16:24:25 OK 20251210153512_drop_unused_gin_index.sql (14.25ms)1250--- PASS: TestCacheStatsHandler (1.55s)1251=== CONT TestGCTaskStore_GetReturnsLatest1252--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1253=== CONT TestClientMultipleUploads12542026/09/20 16:24:25 OK 20251218171726_add_pins.sql (29.93ms)12552026/09/20 16:24:25 OK 20260628120000_add_object_size_and_stats.sql (34.81ms)12562026/09/20 16:24:25 OK 20260905000000_add_claims.sql (38.51ms)12572026/09/20 16:24:25 OK 20260920000000_drop_claims.sql (18.57ms)12582026/09/20 16:24:25 goose: successfully migrated database to version: 2026092000000012592026/09/20 16:24:25 OK 1_commit_pending_closure.sql (1.76ms)12602026/09/20 16:24:25 OK 2_object_stats_trigger.sql (323.33µs)12612026/09/20 16:24:25 goose: up to current file version: 21262=== NAME TestOrphanedObjectsGC1263 orphaned_objects_gc_test.go:290: GC Test Summary:1264 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1265 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1266 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1267 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1268 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1269--- PASS: TestOrphanedObjectsGC (2.21s)1270=== CONT TestService_AuthMiddleware_OIDC12712026/09/20 16:24:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59279/oidc12722026-09-20 16:24:25.443 UTC [73553] ERROR: relation "goose_db_version" does not exist at character 3612732026-09-20 16:24:25.443 UTC [73553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1274--- PASS: TestReadProxyHead (1.57s)1275=== CONT TestClientIntegration12762026/09/20 16:24:25 OK 20241026095416_initial_model.sql (63.53ms)12772026/09/20 16:24:25 OK 20251210153512_drop_unused_gin_index.sql (6.3ms)12782026/09/20 16:24:25 OK 20251218171726_add_pins.sql (32.08ms)12792026/09/20 16:24:25 OK 20260628120000_add_object_size_and_stats.sql (30.57ms)12802026/09/20 16:24:25 OK 20260905000000_add_claims.sql (63.87ms)12812026/09/20 16:24:25 WARN Rate limiter enabled after throttle name=s3-test rate=512822026/09/20 16:24:25 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1283=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1284 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101285 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001286--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.39s)1287=== CONT TestCacheConfigHandler1288=== RUN TestCacheConfigHandler/full_config,_no_issuer1289=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1290=== RUN TestCacheConfigHandler/no_cache_url_configured1291=== PAUSE TestCacheConfigHandler/no_cache_url_configured1292=== RUN TestCacheConfigHandler/no_signing_keys1293=== PAUSE TestCacheConfigHandler/no_signing_keys1294=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1295=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1296=== CONT TestClientErrorHandling1297=== RUN TestClientErrorHandling/InvalidStorePath1298=== PAUSE TestClientErrorHandling/InvalidStorePath1299=== RUN TestClientErrorHandling/InvalidAuthToken1300=== PAUSE TestClientErrorHandling/InvalidAuthToken1301=== RUN TestClientErrorHandling/ServerNotAvailable1302=== PAUSE TestClientErrorHandling/ServerNotAvailable1303=== CONT TestService_ReadScope_PublicByDefault13042026/09/20 16:24:25 OK 20260920000000_drop_claims.sql (20.25ms)13052026/09/20 16:24:25 goose: successfully migrated database to version: 2026092000000013062026/09/20 16:24:25 OK 1_commit_pending_closure.sql (3.72ms)13072026/09/20 16:24:25 OK 2_object_stats_trigger.sql (1.05ms)13082026/09/20 16:24:25 goose: up to current file version: 213092026-09-20 16:24:25.824 UTC [73562] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-20 16:24:25.824 UTC [73562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1311--- PASS: TestReadProxyInvalidPath (1.81s)1312=== CONT TestClientCADerivations1313=== NAME TestPinProtectsFromGC1314 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-73286-1319645990/TestPinProtectsFromGC3198429365/001/store/xyr3a50m39n8rakfcp0sgwir857rnkh0-pinned-file.txt1315 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-73286-1319645990/TestPinProtectsFromGC3198429365/001/store/a2rq7ma3614rzf3i2nkh9s9m4zhf6rwr-unpinned-file.txt13162026/09/20 16:24:25 OK 20241026095416_initial_model.sql (79.7ms)13172026/09/20 16:24:25 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)13182026/09/20 16:24:25 OK 20251218171726_add_pins.sql (7.11ms)13192026/09/20 16:24:25 OK 20260628120000_add_object_size_and_stats.sql (17.53ms)13202026/09/20 16:24:26 OK 20260905000000_add_claims.sql (30.35ms)13212026/09/20 16:24:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13222026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (23.42ms)13232026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000013242026/09/20 16:24:26 OK 1_commit_pending_closure.sql (1.59ms)13252026/09/20 16:24:26 OK 2_object_stats_trigger.sql (370.42µs)13262026/09/20 16:24:26 goose: up to current file version: 213272026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures13282026/09/20 16:24:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13292026/09/20 16:24:26 INFO Uploading xyr3a50m39n8rakfcp0sgwir857rnkh0-pinned-file.txt (128B)13302026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13312026/09/20 16:24:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13322026/09/20 16:24:26 WARN Failed to register uploaded object key=xyr3a50m39n8rakfcp0sgwir857rnkh0.ls error="server returned 404: 404 page not found\n"13332026/09/20 16:24:26 INFO Signed narinfos id=1 count=113342026/09/20 16:24:26 INFO Uploading 1 narinfos13352026/09/20 16:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13362026/09/20 16:24:26 WARN Failed to register uploaded object key=xyr3a50m39n8rakfcp0sgwir857rnkh0.narinfo error="server returned 404: 404 page not found\n"13372026/09/20 16:24:26 INFO Completed upload id=113382026/09/20 16:24:26 INFO Upload complete. (175ms)13392026/09/20 16:24:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1340--- PASS: TestReadProxy404 (1.66s)1341=== CONT TestService_RequireScope_OIDC13422026/09/20 16:24:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59298/oidc13432026-09-20 16:24:26.214 UTC [73584] ERROR: relation "goose_db_version" does not exist at character 3613442026-09-20 16:24:26.214 UTC [73584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13452026-09-20 16:24:26.224 UTC [73588] ERROR: relation "goose_db_version" does not exist at character 3613462026-09-20 16:24:26.224 UTC [73588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13472026/09/20 16:24:26 OK 20241026095416_initial_model.sql (6.75ms)13482026/09/20 16:24:26 OK 20251210153512_drop_unused_gin_index.sql (749.29µs)13492026/09/20 16:24:26 OK 20251218171726_add_pins.sql (2.2ms)13502026/09/20 16:24:26 OK 20241026095416_initial_model.sql (9.76ms)13512026/09/20 16:24:26 OK 20251210153512_drop_unused_gin_index.sql (390.29µs)13522026/09/20 16:24:26 OK 20260628120000_add_object_size_and_stats.sql (5.08ms)13532026/09/20 16:24:26 OK 20251218171726_add_pins.sql (1.03ms)13542026/09/20 16:24:26 OK 20260905000000_add_claims.sql (1.01ms)13552026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (882.71µs)13562026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000013572026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures13582026/09/20 16:24:26 OK 1_commit_pending_closure.sql (1.42ms)13592026/09/20 16:24:26 OK 2_object_stats_trigger.sql (325.58µs)13602026/09/20 16:24:26 goose: up to current file version: 213612026/09/20 16:24:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13622026/09/20 16:24:26 INFO Uploading a2rq7ma3614rzf3i2nkh9s9m4zhf6rwr-unpinned-file.txt (128B)13632026/09/20 16:24:26 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)13642026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13652026/09/20 16:24:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13662026/09/20 16:24:26 INFO Signed narinfos id=2 count=113672026/09/20 16:24:26 WARN Failed to register uploaded object key=a2rq7ma3614rzf3i2nkh9s9m4zhf6rwr.ls error="server returned 404: 404 page not found\n"13682026/09/20 16:24:26 INFO Uploading 1 narinfos13692026/09/20 16:24:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13702026/09/20 16:24:26 OK 20260905000000_add_claims.sql (28.59ms)13712026/09/20 16:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13722026/09/20 16:24:26 WARN Failed to register uploaded object key=a2rq7ma3614rzf3i2nkh9s9m4zhf6rwr.narinfo error="server returned 404: 404 page not found\n"13732026/09/20 16:24:26 INFO Completed upload id=213742026/09/20 16:24:26 INFO Upload complete. (118ms)13752026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (15.47ms)13762026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000013772026/09/20 16:24:26 OK 1_commit_pending_closure.sql (2.22ms)13782026/09/20 16:24:26 OK 2_object_stats_trigger.sql (694.83µs)13792026/09/20 16:24:26 goose: up to current file version: 213802026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures13812026/09/20 16:24:26 INFO Received create pin request method=POST path=/api/pins/myapp13822026/09/20 16:24:26 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-73286-1319645990/TestPinProtectsFromGC3198429365/001/store/xyr3a50m39n8rakfcp0sgwir857rnkh0-pinned-file.txt narinfo_key=xyr3a50m39n8rakfcp0sgwir857rnkh0.narinfo13832026/09/20 16:24:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures13842026/09/20 16:24:26 INFO Garbage collection started13852026/09/20 16:24:26 INFO Aborted multipart uploads count=013862026/09/20 16:24:26 WARN Force mode enabled - objects will be deleted immediately without grace period13872026/09/20 16:24:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13882026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures13892026/09/20 16:24:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13902026/09/20 16:24:26 INFO Uploading 7apfmd3pdr5dm540ajjg5rgg401z1ka0-shared-dep (136B)13912026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13922026/09/20 16:24:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13932026/09/20 16:24:26 INFO Signed narinfos id=2 count=113942026/09/20 16:24:26 WARN Failed to register uploaded object key=7apfmd3pdr5dm540ajjg5rgg401z1ka0.ls error="server returned 404: 404 page not found\n"13952026/09/20 16:24:26 INFO Uploading 1 narinfos13962026/09/20 16:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13972026/09/20 16:24:26 WARN Failed to register uploaded object key=7apfmd3pdr5dm540ajjg5rgg401z1ka0.narinfo error="server returned 404: 404 page not found\n"13982026-09-20 16:24:26.510 UTC [73604] ERROR: relation "goose_db_version" does not exist at character 3613992026-09-20 16:24:26.510 UTC [73604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14002026/09/20 16:24:26 INFO Completed upload id=214012026/09/20 16:24:26 INFO Upload complete. (163ms)14022026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures14032026/09/20 16:24:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14042026/09/20 16:24:26 INFO Uploading 7j5ki5dpkmyw65vfpahszm1d71h2r81b-top (256B)14052026/09/20 16:24:26 INFO Uploading 7apfmd3pdr5dm540ajjg5rgg401z1ka0-shared-dep (136B)14062026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/1lly19drj9zi2b7zjl4fpa0ix4mwss2adwl63zsz82vj9lxib1p3.nar.zst error="server returned 404: 404 page not found\n"14072026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14082026/09/20 16:24:26 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=014092026/09/20 16:24:26 WARN Failed to register uploaded object key=7j5ki5dpkmyw65vfpahszm1d71h2r81b.ls error="server returned 404: 404 page not found\n"14102026/09/20 16:24:26 INFO Vacuumed table table=pending_closures14112026/09/20 16:24:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14122026/09/20 16:24:26 INFO Signed narinfos id=1 count=114132026/09/20 16:24:26 WARN Failed to register uploaded object key=7apfmd3pdr5dm540ajjg5rgg401z1ka0.ls error="server returned 404: 404 page not found\n"14142026/09/20 16:24:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14152026/09/20 16:24:26 INFO Signed narinfos id=3 count=114162026/09/20 16:24:26 INFO Uploading 2 narinfos14172026-09-20 16:24:26.595 UTC [73606] ERROR: relation "goose_db_version" does not exist at character 3614182026-09-20 16:24:26.595 UTC [73606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/09/20 16:24:26 WARN Failed to register uploaded object key=7j5ki5dpkmyw65vfpahszm1d71h2r81b.narinfo error="server returned 404: 404 page not found\n"14202026/09/20 16:24:26 INFO Vacuumed table table=pending_objects14212026/09/20 16:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14222026/09/20 16:24:26 WARN Failed to register uploaded object key=7apfmd3pdr5dm540ajjg5rgg401z1ka0.narinfo error="server returned 404: 404 page not found\n"14232026/09/20 16:24:26 INFO Completed upload id=114242026/09/20 16:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14252026/09/20 16:24:26 INFO Completed upload id=314262026/09/20 16:24:26 INFO Upload complete. (389ms)14272026/09/20 16:24:26 INFO Vacuumed table table=multipart_uploads1428=== NAME TestClientSharedPathCommittedMidPush1429 client_integration_test.go:680: Retrieved narinfo from S3:1430 StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestClientSharedPathCommittedMidPush2298032804/001/store/7apfmd3pdr5dm540ajjg5rgg401z1ka0-shared-dep1431 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1432 Compression: zstd1433 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821434 NarSize: 1361435 References: 1436 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1437 client_integration_test.go:680: Retrieved narinfo from S3:1438 StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestClientSharedPathCommittedMidPush2298032804/001/store/7j5ki5dpkmyw65vfpahszm1d71h2r81b-top1439 URL: nar/1lly19drj9zi2b7zjl4fpa0ix4mwss2adwl63zsz82vj9lxib1p3.nar.zst1440 Compression: zstd1441 NarHash: sha256:1lly19drj9zi2b7zjl4fpa0ix4mwss2adwl63zsz82vj9lxib1p31442 NarSize: 2561443 References: /nix/var/nix/builds/nix-73286-1319645990/TestClientSharedPathCommittedMidPush2298032804/001/store/7apfmd3pdr5dm540ajjg5rgg401z1ka0-shared-dep1444 CA: text:sha256:1670n3ynm3ph6ng8901l0plxvkjxcqj5bny2h2gc6jwv72njrmq414452026/09/20 16:24:26 INFO Vacuumed table table=closures14462026/09/20 16:24:26 INFO Vacuumed table table=objects1447--- PASS: TestClientSharedPathCommittedMidPush (2.37s)1448=== CONT TestGCMetrics14492026/09/20 16:24:26 OK 20241026095416_initial_model.sql (83.2ms)14502026/09/20 16:24:26 OK 20251210153512_drop_unused_gin_index.sql (7.36ms)14512026/09/20 16:24:26 OK 20251218171726_add_pins.sql (63.78ms)14522026/09/20 16:24:26 OK 20241026095416_initial_model.sql (105.56ms)14532026-09-20 16:24:26.738 UTC [73613] ERROR: relation "goose_db_version" does not exist at character 3614542026-09-20 16:24:26.738 UTC [73613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14552026/09/20 16:24:26 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)14562026/09/20 16:24:26 OK 20260628120000_add_object_size_and_stats.sql (10.63ms)14572026/09/20 16:24:26 OK 20251218171726_add_pins.sql (11.6ms)14582026/09/20 16:24:26 OK 20260628120000_add_object_size_and_stats.sql (19.97ms)14592026/09/20 16:24:26 OK 20260905000000_add_claims.sql (22.55ms)14602026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (11.35ms)14612026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000014622026/09/20 16:24:26 OK 1_commit_pending_closure.sql (1.21ms)14632026/09/20 16:24:26 OK 2_object_stats_trigger.sql (225.21µs)14642026/09/20 16:24:26 goose: up to current file version: 214652026/09/20 16:24:26 OK 20260905000000_add_claims.sql (19.54ms)14662026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (29.64ms)14672026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000014682026/09/20 16:24:26 OK 1_commit_pending_closure.sql (936.88µs)14692026/09/20 16:24:26 OK 2_object_stats_trigger.sql (223.58µs)14702026/09/20 16:24:26 goose: up to current file version: 21471=== NAME TestClientMultipleUploads1472 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-73286-1319645990/TestClientMultipleUploads223033037/001/store/3k4vyi7qq3m2vl0l4miwvxzkg4ph5067-test-file-0.txt1473=== NAME TestClientWithDependencies1474 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-73286-1319645990/TestClientWithDependencies3463293291/001/store/7xpbpiiy4imhh4pxvdn5x70apnxr96ba-test-script14752026-09-20 16:24:26.844 UTC [73615] ERROR: relation "goose_db_version" does not exist at character 3614762026-09-20 16:24:26.844 UTC [73615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/09/20 16:24:26 OK 20241026095416_initial_model.sql (106.11ms)1478 client_integration_test.go:615: Found 1 dependencies (including self)14792026/09/20 16:24:26 OK 20251210153512_drop_unused_gin_index.sql (15.45ms)14802026/09/20 16:24:26 OK 20251218171726_add_pins.sql (15.43ms)1481=== NAME TestClientMultipleUploads1482 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-73286-1319645990/TestClientMultipleUploads223033037/001/store/xdsqgf6xszhjahw5afs589a58lbbxy4l-test-file-1.txt14832026/09/20 16:24:26 OK 20260628120000_add_object_size_and_stats.sql (19.85ms)14842026/09/20 16:24:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14852026/09/20 16:24:26 INFO Received uploads request method=POST path=/api/pending_closures14862026/09/20 16:24:26 OK 20260905000000_add_claims.sql (34.61ms)14872026/09/20 16:24:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14882026/09/20 16:24:26 INFO Uploading 7xpbpiiy4imhh4pxvdn5x70apnxr96ba-test-script (136B)1489 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-73286-1319645990/TestClientMultipleUploads223033037/001/store/m2qdxfs3xbd25kfr125rf5xj9y2gfll3-test-file-2.txt14902026/09/20 16:24:26 OK 20260920000000_drop_claims.sql (10.85ms)14912026/09/20 16:24:26 goose: successfully migrated database to version: 2026092000000014922026/09/20 16:24:26 OK 1_commit_pending_closure.sql (843.88µs)14932026/09/20 16:24:26 OK 2_object_stats_trigger.sql (236.83µs)14942026/09/20 16:24:26 goose: up to current file version: 214952026/09/20 16:24:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14962026/09/20 16:24:26 WARN Failed to register uploaded object key=log/fn6hm3qy0js729w8r9gkjdn1sq966s0h-test-script.drv error="server returned 404: 404 page not found\n"14972026/09/20 16:24:27 OK 20241026095416_initial_model.sql (102.41ms)14982026/09/20 16:24:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14992026/09/20 16:24:27 WARN Failed to register uploaded object key=7xpbpiiy4imhh4pxvdn5x70apnxr96ba.ls error="server returned 404: 404 page not found\n"15002026/09/20 16:24:27 INFO Signed narinfos id=1 count=115012026/09/20 16:24:27 INFO Uploading 1 narinfos15022026/09/20 16:24:27 OK 20251210153512_drop_unused_gin_index.sql (9.23ms)15032026/09/20 16:24:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15042026/09/20 16:24:27 WARN Failed to register uploaded object key=7xpbpiiy4imhh4pxvdn5x70apnxr96ba.narinfo error="server returned 404: 404 page not found\n"15052026/09/20 16:24:27 OK 20251218171726_add_pins.sql (17.91ms)15062026/09/20 16:24:27 INFO Completed upload id=115072026/09/20 16:24:27 INFO Upload complete. (125ms)1508=== NAME TestClientWithDependencies1509 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-73286-1319645990/TestClientWithDependencies3463293291/001/store) requires matching store prefix15102026/09/20 16:24:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15112026/09/20 16:24:27 OK 20260628120000_add_object_size_and_stats.sql (39.16ms)1512--- PASS: TestClientWithDependencies (2.13s)1513=== CONT TestGCTaskStore_ConflictDifferentParams1514--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1515=== CONT TestGCTaskStore_DeduplicateSameParams1516--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1517=== CONT TestGCTaskStore_StartNew1518--- PASS: TestGCTaskStore_StartNew (0.00s)1519=== CONT TestService_ReadAuthMiddleware15202026/09/20 16:24:27 OK 20260905000000_add_claims.sql (34.04ms)15212026/09/20 16:24:27 OK 20260920000000_drop_claims.sql (26.59ms)15222026/09/20 16:24:27 goose: successfully migrated database to version: 2026092000000015232026/09/20 16:24:27 OK 1_commit_pending_closure.sql (1.16ms)15242026/09/20 16:24:27 INFO Received uploads request method=POST path=/api/pending_closures15252026/09/20 16:24:27 OK 2_object_stats_trigger.sql (254.42µs)15262026/09/20 16:24:27 goose: up to current file version: 215272026/09/20 16:24:27 INFO Received uploads request method=POST path=/api/pending_closures15282026/09/20 16:24:27 INFO Received uploads request method=POST path=/api/pending_closures15292026/09/20 16:24:27 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15302026/09/20 16:24:27 INFO Uploading xdsqgf6xszhjahw5afs589a58lbbxy4l-test-file-1.txt (160B)15312026/09/20 16:24:27 INFO Uploading 3k4vyi7qq3m2vl0l4miwvxzkg4ph5067-test-file-0.txt (160B)15322026/09/20 16:24:27 INFO Uploading m2qdxfs3xbd25kfr125rf5xj9y2gfll3-test-file-2.txt (160B)15332026/09/20 16:24:27 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15342026/09/20 16:24:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15352026/09/20 16:24:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1536=== NAME TestClientIntegration1537 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-73286-1319645990/TestClientIntegration3422745182/002/store/w9g1mvmipyhj7d29fkm3p8g0aw2caxn3-test-file.txt15382026/09/20 16:24:27 WARN Failed to register uploaded object key=xdsqgf6xszhjahw5afs589a58lbbxy4l.ls error="server returned 404: 404 page not found\n"15392026/09/20 16:24:27 WARN Failed to register uploaded object key=3k4vyi7qq3m2vl0l4miwvxzkg4ph5067.ls error="server returned 404: 404 page not found\n"15402026-09-20 16:24:27.170 UTC [73636] ERROR: relation "goose_db_version" does not exist at character 3615412026-09-20 16:24:27.170 UTC [73636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15422026/09/20 16:24:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15432026/09/20 16:24:27 WARN Failed to register uploaded object key=m2qdxfs3xbd25kfr125rf5xj9y2gfll3.ls error="server returned 404: 404 page not found\n"15442026/09/20 16:24:27 INFO Signed narinfos id=1 count=115452026/09/20 16:24:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15462026/09/20 16:24:27 INFO Signed narinfos id=2 count=115472026/09/20 16:24:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15482026/09/20 16:24:27 INFO Signed narinfos id=3 count=115492026/09/20 16:24:27 INFO Uploading 3 narinfos15502026/09/20 16:24:27 WARN Failed to register uploaded object key=3k4vyi7qq3m2vl0l4miwvxzkg4ph5067.narinfo error="server returned 404: 404 page not found\n"15512026/09/20 16:24:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15522026/09/20 16:24:27 WARN Failed to register uploaded object key=m2qdxfs3xbd25kfr125rf5xj9y2gfll3.narinfo error="server returned 404: 404 page not found\n"15532026/09/20 16:24:27 WARN Failed to register uploaded object key=xdsqgf6xszhjahw5afs589a58lbbxy4l.narinfo error="server returned 404: 404 page not found\n"15542026/09/20 16:24:27 INFO Completed upload id=115552026/09/20 16:24:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15562026/09/20 16:24:27 INFO Completed upload id=215572026/09/20 16:24:27 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15582026/09/20 16:24:27 INFO Completed upload id=315592026/09/20 16:24:27 INFO Upload complete. (195ms)1560=== NAME TestClientMultipleUploads1561 client_integration_test.go:369: Uploaded 3 paths in 226.864916ms15622026/09/20 16:24:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1563=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1564=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1565=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1566=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1567=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1568=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1569=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1570=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1571=== CONT TestLeadEndsOnShutdown1572--- PASS: TestClientMultipleUploads (2.02s)1573=== CONT TestGCBugBareHashReferences15742026/09/20 16:24:27 INFO Received uploads request method=POST path=/api/pending_closures15752026/09/20 16:24:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15762026/09/20 16:24:27 INFO Uploading w9g1mvmipyhj7d29fkm3p8g0aw2caxn3-test-file.txt (152B)15772026/09/20 16:24:27 OK 20241026095416_initial_model.sql (89.83ms)15782026/09/20 16:24:27 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)15792026/09/20 16:24:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15802026/09/20 16:24:27 OK 20251218171726_add_pins.sql (12.93ms)15812026/09/20 16:24:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15822026/09/20 16:24:27 INFO Signed narinfos id=1 count=115832026/09/20 16:24:27 WARN Failed to register uploaded object key=w9g1mvmipyhj7d29fkm3p8g0aw2caxn3.ls error="server returned 404: 404 page not found\n"15842026/09/20 16:24:27 INFO Uploading 1 narinfos15852026/09/20 16:24:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15862026/09/20 16:24:27 WARN Failed to register uploaded object key=w9g1mvmipyhj7d29fkm3p8g0aw2caxn3.narinfo error="server returned 404: 404 page not found\n"15872026/09/20 16:24:27 OK 20260628120000_add_object_size_and_stats.sql (17.41ms)15882026/09/20 16:24:27 INFO Completed upload id=115892026/09/20 16:24:27 INFO Upload complete. (139ms)15902026/09/20 16:24:27 OK 20260905000000_add_claims.sql (28.45ms)15912026/09/20 16:24:27 INFO All 1 paths already cached1592=== NAME TestClientIntegration1593 client_integration_test.go:312: Retrieved narinfo from S3:1594 StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestClientIntegration3422745182/002/store/w9g1mvmipyhj7d29fkm3p8g0aw2caxn3-test-file.txt1595 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1596 Compression: zstd1597 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11598 NarSize: 1521599 References: 1600 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116012026/09/20 16:24:27 OK 20260920000000_drop_claims.sql (14.59ms)16022026/09/20 16:24:27 goose: successfully migrated database to version: 202609200000001603 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1604 client_integration_test.go:313: Decompressed .ls content (64 bytes):1605 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1606 client_integration_test.go:316: Testing garbage collection...16072026/09/20 16:24:27 OK 1_commit_pending_closure.sql (1.17ms)16082026/09/20 16:24:27 OK 2_object_stats_trigger.sql (324.92µs)16092026/09/20 16:24:27 goose: up to current file version: 216102026/09/20 16:24:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures16112026/09/20 16:24:27 INFO Garbage collection started16122026/09/20 16:24:27 INFO Aborted multipart uploads count=016132026/09/20 16:24:27 WARN Force mode enabled - objects will be deleted immediately without grace period1614--- PASS: TestService_ReadScope_PublicByDefault (1.73s)1615=== CONT TestLeadElectsOneAndHandsOver16162026/09/20 16:24:27 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=016172026/09/20 16:24:27 INFO Vacuumed table table=pending_closures16182026/09/20 16:24:27 INFO Vacuumed table table=pending_objects16192026/09/20 16:24:27 INFO Vacuumed table table=multipart_uploads16202026/09/20 16:24:27 INFO Vacuumed table table=closures1621=== NAME TestOrphanedObjectsGCStressTest1622 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16232026/09/20 16:24:27 INFO Vacuumed table table=objects16242026-09-20 16:24:27.725 UTC [73655] ERROR: relation "goose_db_version" does not exist at character 3616252026-09-20 16:24:27.725 UTC [73655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1626 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1627=== RUN TestService_RequireScope_OIDC/builder_may_write1628=== PAUSE TestService_RequireScope_OIDC/builder_may_write1629=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1630=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1631=== RUN TestService_RequireScope_OIDC/ops_may_admin1632=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1633=== RUN TestService_RequireScope_OIDC/ops_may_not_write1634=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1635=== RUN TestService_RequireScope_OIDC/reader_may_not_write1636=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1637=== RUN TestService_RequireScope_OIDC/static_token_may_admin1638=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1639=== RUN TestService_RequireScope_OIDC/static_token_may_write1640=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1641=== RUN TestService_RequireScope_OIDC/reader_may_read1642=== PAUSE TestService_RequireScope_OIDC/reader_may_read1643=== RUN TestService_RequireScope_OIDC/writer_implies_read1644=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1645=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1646=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1647=== CONT TestMetricsInventory16482026/09/20 16:24:27 OK 20241026095416_initial_model.sql (139.18ms)16492026/09/20 16:24:27 OK 20251210153512_drop_unused_gin_index.sql (6.6ms)16502026/09/20 16:24:27 OK 20251218171726_add_pins.sql (1.91ms)16512026/09/20 16:24:27 OK 20260628120000_add_object_size_and_stats.sql (21.17ms)16522026/09/20 16:24:27 OK 20260905000000_add_claims.sql (10.11ms)16532026/09/20 16:24:27 OK 20260920000000_drop_claims.sql (1.09ms)16542026/09/20 16:24:27 goose: successfully migrated database to version: 2026092000000016552026/09/20 16:24:27 OK 1_commit_pending_closure.sql (2.05ms)16562026/09/20 16:24:27 OK 2_object_stats_trigger.sql (287.33µs)16572026/09/20 16:24:27 goose: up to current file version: 21658=== NAME TestClientCADerivations1659 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-73286-1319645990/TestClientCADerivations2479182012/001/store/y4fj8wb2n9p4w0rfw6jcwm3b3hqykspr-ca-test16602026-09-20 16:24:28.027 UTC [73663] ERROR: relation "goose_db_version" does not exist at character 3616612026-09-20 16:24:28.027 UTC [73663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1662 client_ca_test.go:139: Found 1 dependencies (including self)16632026/09/20 16:24:28 OK 20241026095416_initial_model.sql (46.84ms)16642026/09/20 16:24:28 INFO Aborted multipart uploads count=016652026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (919.46µs)16662026/09/20 16:24:28 OK 20251218171726_add_pins.sql (7.65ms)16672026-09-20 16:24:28.106 UTC [73671] ERROR: relation "goose_db_version" does not exist at character 3616682026-09-20 16:24:28.106 UTC [73671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16692026-09-20 16:24:28.106 UTC [73670] ERROR: relation "goose_db_version" does not exist at character 3616702026-09-20 16:24:28.106 UTC [73670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16712026/09/20 16:24:28 WARN Force mode enabled - objects will be deleted immediately without grace period16722026/09/20 16:24:28 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=016732026/09/20 16:24:28 INFO Vacuumed table table=pending_closures16742026/09/20 16:24:28 INFO Vacuumed table table=pending_objects16752026/09/20 16:24:28 INFO Vacuumed table table=multipart_uploads16762026/09/20 16:24:28 INFO Vacuumed table table=closures16772026/09/20 16:24:28 INFO Vacuumed table table=objects1678--- PASS: TestGCMetrics (1.46s)1679=== CONT TestMultipartCleanup16802026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (11.56ms)16812026/09/20 16:24:28 OK 20260905000000_add_claims.sql (2.26ms)16822026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (875.46µs)16832026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000016842026/09/20 16:24:28 OK 1_commit_pending_closure.sql (1.61ms)16852026/09/20 16:24:28 OK 20241026095416_initial_model.sql (5.55ms)16862026/09/20 16:24:28 OK 2_object_stats_trigger.sql (487.5µs)16872026/09/20 16:24:28 goose: up to current file version: 216882026/09/20 16:24:28 OK 20241026095416_initial_model.sql (4.76ms)16892026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (763.75µs)16902026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (597.5µs)16912026/09/20 16:24:28 OK 20251218171726_add_pins.sql (1.85ms)16922026/09/20 16:24:28 OK 20251218171726_add_pins.sql (1.73ms)16932026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (37.13ms)16942026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (37.64ms)16952026/09/20 16:24:28 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16962026/09/20 16:24:28 OK 20260905000000_add_claims.sql (18.13ms)16972026/09/20 16:24:28 OK 20260905000000_add_claims.sql (19.33ms)16982026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (1.12ms)16992026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000017002026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (2.17ms)17012026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000017022026/09/20 16:24:28 OK 1_commit_pending_closure.sql (1.46ms)17032026/09/20 16:24:28 OK 2_object_stats_trigger.sql (293.21µs)17042026/09/20 16:24:28 goose: up to current file version: 217052026/09/20 16:24:28 OK 1_commit_pending_closure.sql (835.38µs)17062026/09/20 16:24:28 OK 2_object_stats_trigger.sql (186.08µs)17072026/09/20 16:24:28 goose: up to current file version: 217082026/09/20 16:24:28 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/20 16:24:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17102026/09/20 16:24:28 INFO Uploading y4fj8wb2n9p4w0rfw6jcwm3b3hqykspr-ca-test (144B)17112026/09/20 16:24:28 WARN Failed to register uploaded object key=log/x1hrpd7p42lkcpph55d8hcgn6xnp9nay-ca-test.drv error="server returned 404: 404 page not found\n"17122026/09/20 16:24:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17132026/09/20 16:24:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17142026/09/20 16:24:28 INFO Signed narinfos id=1 count=117152026/09/20 16:24:28 WARN Failed to register uploaded object key=y4fj8wb2n9p4w0rfw6jcwm3b3hqykspr.ls error="server returned 404: 404 page not found\n"17162026/09/20 16:24:28 INFO Uploading 1 narinfos17172026/09/20 16:24:28 WARN Failed to register uploaded object key=y4fj8wb2n9p4w0rfw6jcwm3b3hqykspr.narinfo error="server returned 404: 404 page not found\n"17182026/09/20 16:24:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17192026/09/20 16:24:28 INFO Completed upload id=117202026/09/20 16:24:28 INFO Upload complete. (151ms)1721=== NAME TestClientCADerivations1722 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestClientCADerivations2479182012/001/store/y4fj8wb2n9p4w0rfw6jcwm3b3hqykspr-ca-test1723 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1724 Compression: zstd1725 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1726 NarSize: 1441727 References: 1728 Deriver: /nix/var/nix/builds/nix-73286-1319645990/TestClientCADerivations2479182012/001/store/x1hrpd7p42lkcpph55d8hcgn6xnp9nay-ca-test.drv1729 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1730 client_ca_test.go:185: Checking for realisation files in S3...1731 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1732 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1733--- PASS: TestService_ReadAuthMiddleware (1.21s)1734=== CONT TestServerTLSConfig1735=== RUN TestServerTLSConfig/no_client_CA1736=== PAUSE TestServerTLSConfig/no_client_CA1737=== RUN TestServerTLSConfig/missing_CA_file1738=== PAUSE TestServerTLSConfig/missing_CA_file1739=== RUN TestServerTLSConfig/not_a_PEM_file1740=== PAUSE TestServerTLSConfig/not_a_PEM_file1741=== CONT TestService_NativeMTLS17422026-09-20 16:24:28.315 UTC [73680] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-20 16:24:28.315 UTC [73680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17442026/09/20 16:24:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01745=== NAME TestPinProtectsFromGC1746 client_integration_test.go:794: Pin successfully protected closure from garbage collection1747=== NAME TestClientCADerivations1748 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket40?endpoint=http://localhost:59203®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-73286-1319645990/TestClientCADerivations2479182012/001/store'1749 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11750--- PASS: TestPinProtectsFromGC (4.38s)1751=== CONT TestCreatePendingClosureRejectsOversizedNAR17522026/09/20 16:24:28 INFO Received uploads request method=POST path=/api/pending_closures1753--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1754=== CONT TestNARDeduplicationMetadataUploadBug1755--- PASS: TestClientCADerivations (2.47s)1756=== CONT TestService_AuthMiddleware_MTLSProxyHeader17572026/09/20 16:24:28 OK 20241026095416_initial_model.sql (57.06ms)17582026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (39.26ms)17592026/09/20 16:24:28 OK 20251218171726_add_pins.sql (15.37ms)17602026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (27.41ms)17612026/09/20 16:24:28 INFO lead: acquired remote=192.0.2.1:123417622026/09/20 16:24:28 INFO lead: released remote=192.0.2.1:12341763--- PASS: TestLeadEndsOnShutdown (1.23s)1764=== CONT TestCacheConfigHandlerMaxNarSize1765--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1766=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17672026/09/20 16:24:28 OK 20260905000000_add_claims.sql (3.2ms)17682026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (7.89ms)17692026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000017702026/09/20 16:24:28 OK 1_commit_pending_closure.sql (1.02ms)17712026/09/20 16:24:28 OK 2_object_stats_trigger.sql (284.25µs)17722026/09/20 16:24:28 goose: up to current file version: 217732026-09-20 16:24:28.590 UTC [73688] ERROR: relation "goose_db_version" does not exist at character 3617742026-09-20 16:24:28.590 UTC [73688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17752026/09/20 16:24:28 OK 20241026095416_initial_model.sql (44.86ms)17762026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)17772026/09/20 16:24:28 OK 20251218171726_add_pins.sql (20.31ms)17782026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (23.73ms)17792026/09/20 16:24:28 OK 20260905000000_add_claims.sql (35.41ms)17802026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (15.2ms)17812026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000017822026/09/20 16:24:28 OK 1_commit_pending_closure.sql (2.5ms)17832026/09/20 16:24:28 OK 2_object_stats_trigger.sql (386.33µs)17842026/09/20 16:24:28 goose: up to current file version: 217852026-09-20 16:24:28.803 UTC [73689] ERROR: relation "goose_db_version" does not exist at character 3617862026-09-20 16:24:28.803 UTC [73689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17872026/09/20 16:24:28 INFO lead: acquired remote=192.0.2.1:12341788--- PASS: TestGCBugBareHashReferences (1.61s)1789=== CONT TestResolveDBConnectionString/flag_wins1790=== CONT TestResolveDBConnectionString/nothing_configured1791=== CONT TestResolveDBConnectionString/missing_file_is_an_error1792=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1793=== CONT TestResolveDBConnectionString/file_when_flag_empty1794=== CONT TestProxyWriteTimeout/narinfo1795=== CONT TestProxyWriteTimeout/10_GiB_nar1796=== CONT TestProxyWriteTimeout/unknown_size1797=== CONT TestProxyWriteTimeout/1_GiB_nar1798--- PASS: TestProxyWriteTimeout (0.00s)1799 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1800 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1801 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1802 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1803=== CONT TestService_healthCheckHandler1804--- PASS: TestResolveDBConnectionString (0.01s)1805 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1806 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1807 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1808 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1809 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18102026/09/20 16:24:28 OK 20241026095416_initial_model.sql (67.79ms)18112026/09/20 16:24:28 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)18122026/09/20 16:24:28 OK 20251218171726_add_pins.sql (16.71ms)18132026/09/20 16:24:28 OK 20260628120000_add_object_size_and_stats.sql (17.96ms)18142026/09/20 16:24:28 OK 20260905000000_add_claims.sql (27.58ms)18152026/09/20 16:24:28 INFO lead: released remote=192.0.2.1:123418162026/09/20 16:24:28 OK 20260920000000_drop_claims.sql (15.99ms)18172026/09/20 16:24:28 goose: successfully migrated database to version: 2026092000000018182026/09/20 16:24:29 OK 1_commit_pending_closure.sql (33.01ms)18192026/09/20 16:24:29 OK 2_object_stats_trigger.sql (595.75µs)18202026/09/20 16:24:29 goose: up to current file version: 21821=== NAME TestOrphanedObjectsGCStressTest1822 orphaned_objects_gc_test.go:509: Stress test completed successfully:1823 orphaned_objects_gc_test.go:510: - Active objects preserved: 201824 orphaned_objects_gc_test.go:511: - Objects deleted: 2101825 orphaned_objects_gc_test.go:512: - Total GC'd: 2101826--- PASS: TestOrphanedObjectsGCStressTest (6.12s)1827=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18282026/09/20 16:24:29 INFO Received uploads request method=POST path=/18292026/09/20 16:24:29 INFO lead: acquired remote=192.0.2.1:123418302026/09/20 16:24:29 INFO lead: released remote=192.0.2.1:12341831--- PASS: TestLeadElectsOneAndHandsOver (1.59s)1832=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18332026/09/20 16:24:29 INFO Received request for more parts method=POST path=/1834--- PASS: TestMetricsInventory (1.14s)1835=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18362026/09/20 16:24:29 INFO Received complete multipart upload request method=POST path=/1837=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18382026/09/20 16:24:29 INFO Received uploads request method=POST path=/1839=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18402026/09/20 16:24:29 INFO Received complete multipart upload request method=POST path=/1841=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18422026/09/20 16:24:29 INFO Received request for more parts method=POST path=/1843=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18442026/09/20 16:24:29 INFO Received uploads request method=POST path=/1845--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1846 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1847 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1848 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1849 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1850=== CONT TestIsValidUploadKey/narinfo1851=== CONT TestIsValidUploadKey/realisation_plus_in_output1852=== CONT TestIsValidUploadKey/unknown_type1853=== CONT TestIsValidUploadKey/empty_key1854=== CONT TestIsValidUploadKey/absolute1855=== CONT TestIsValidUploadKey/traversal_nar1856=== CONT TestIsValidUploadKey/traversal1857=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1858=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1859=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1860=== CONT TestIsValidUploadKey/index.html1861=== CONT TestIsValidUploadKey/nix-cache-info1862=== CONT TestIsValidUploadKey/build_log_home-manager_file1863=== CONT TestIsValidUploadKey/realisation1864=== CONT TestIsValidUploadKey/build_log_equals1865=== CONT TestIsValidUploadKey/build_log_question_mark1866=== CONT TestIsValidUploadKey/build_log_plus_in_name1867=== CONT TestIsValidUploadKey/nar_plain1868=== CONT TestIsValidUploadKey/build_log1869=== CONT TestIsValidUploadKey/listing1870=== CONT TestIsValidUploadKey/nar_xz1871=== CONT TestIsValidUploadKey/nar_zst1872--- PASS: TestIsValidUploadKey (0.00s)1873 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1874 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1875 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1876 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1877 --- PASS: TestIsValidUploadKey/absolute (0.00s)1878 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1879 --- PASS: TestIsValidUploadKey/traversal (0.00s)1880 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1881 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1882 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1883 --- PASS: TestIsValidUploadKey/index.html (0.00s)1884 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1885 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1886 --- PASS: TestIsValidUploadKey/realisation (0.00s)1887 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1888 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1889 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1890 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1891 --- PASS: TestIsValidUploadKey/build_log (0.00s)1892 --- PASS: TestIsValidUploadKey/listing (0.00s)1893 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1894 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1895=== CONT TestIsValidCachePath/narinfo1896=== CONT TestIsValidCachePath/index.html1897=== CONT TestIsValidCachePath/short_hash1898=== CONT TestIsValidCachePath/wrong_extension1899=== CONT TestIsValidCachePath/leading_slash1900=== CONT TestIsValidCachePath/empty1901=== CONT TestIsValidCachePath/random_path1902=== CONT TestIsValidCachePath/invalid_char_u1903=== CONT TestIsValidCachePath/invalid_char_e1904=== CONT TestIsValidCachePath/traversal_in_middle1905=== CONT TestIsValidCachePath/traversal_parent1906=== CONT TestIsValidCachePath/nar_uncompressed1907=== CONT TestIsValidCachePath/nix-cache-info1908=== CONT TestIsValidCachePath/realisation1909=== CONT TestIsValidCachePath/log1910=== CONT TestIsValidCachePath/ls1911=== CONT TestIsValidCachePath/nar_bz21912=== CONT TestIsValidCachePath/nar_zst1913=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1914=== CONT TestIsValidCachePath/nar_xz1915--- PASS: TestIsValidCachePath (0.00s)1916 --- PASS: TestIsValidCachePath/narinfo (0.00s)1917 --- PASS: TestIsValidCachePath/index.html (0.00s)1918 --- PASS: TestIsValidCachePath/short_hash (0.00s)1919 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1920 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1921 --- PASS: TestIsValidCachePath/empty (0.00s)1922 --- PASS: TestIsValidCachePath/random_path (0.00s)1923 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1924 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1925 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1926 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1927 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1928 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1929 --- PASS: TestIsValidCachePath/realisation (0.00s)1930 --- PASS: TestIsValidCachePath/log (0.00s)1931 --- PASS: TestIsValidCachePath/ls (0.00s)1932 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1933 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1934 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1935 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1936=== CONT TestParseSingleRange/none1937=== CONT TestParseSingleRange/open-ended1938=== CONT TestParseSingleRange/start_far_past_EOF1939=== CONT TestParseSingleRange/start_past_EOF1940=== CONT TestParseSingleRange/single_byte1941=== CONT TestParseSingleRange/suffix_exceeds_size1942=== CONT TestParseSingleRange/suffix1943=== CONT TestParseSingleRange/end_clamped_to_size1944=== CONT TestParseSingleRange/multi-range_ignored1945=== CONT TestParseSingleRange/malformed_no_dash1946=== CONT TestParseSingleRange/closed1947=== CONT TestParseSingleRange/malformed_end_before_start1948=== CONT TestParseSingleRange/unknown_unit1949=== CONT TestParseSingleRange/malformed_both_empty1950--- PASS: TestParseSingleRange (0.00s)1951 --- PASS: TestParseSingleRange/none (0.00s)1952 --- PASS: TestParseSingleRange/open-ended (0.00s)1953 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1954 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1955 --- PASS: TestParseSingleRange/single_byte (0.00s)1956 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1957 --- PASS: TestParseSingleRange/suffix (0.00s)1958 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1959 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1960 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1961 --- PASS: TestParseSingleRange/closed (0.00s)1962 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1963 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1964 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1965=== CONT TestCacheConfigHandler/full_config,_no_issuer1966=== CONT TestClientErrorHandling/InvalidStorePath1967=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1968=== CONT TestCacheConfigHandler/no_signing_keys1969=== CONT TestCacheConfigHandler/no_cache_url_configured1970--- PASS: TestCacheConfigHandler (0.00s)1971 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1972 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1973 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1974 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1975=== CONT TestClientErrorHandling/ServerNotAvailable19762026-09-20 16:24:29.136 UTC [73698] ERROR: relation "goose_db_version" does not exist at character 3619772026-09-20 16:24:29.136 UTC [73698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/09/20 16:24:29 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/present19792026/09/20 16:24:29 INFO Received uploads request method=POST path=/api/pending_closures19802026-09-20 16:24:29.202 UTC [73701] ERROR: relation "goose_db_version" does not exist at character 3619812026-09-20 16:24:29.202 UTC [73701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19822026-09-20 16:24:29.205 UTC [73702] ERROR: relation "goose_db_version" does not exist at character 3619832026-09-20 16:24:29.205 UTC [73702] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19842026/09/20 16:24:29 OK 20241026095416_initial_model.sql (37.86ms)19852026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (10.43ms)19862026/09/20 16:24:29 OK 20251218171726_add_pins.sql (8.61ms)19872026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (12.53ms)19882026/09/20 16:24:29 OK 20260905000000_add_claims.sql (1.9ms)19892026/09/20 16:24:29 OK 20241026095416_initial_model.sql (16.32ms)19902026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (601.42µs)19912026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (1.66ms)19922026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000019932026/09/20 16:24:29 OK 20251218171726_add_pins.sql (1ms)19942026/09/20 16:24:29 OK 20241026095416_initial_model.sql (5.75ms)19952026/09/20 16:24:29 OK 1_commit_pending_closure.sql (1.36ms)19962026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (556.83µs)19972026/09/20 16:24:29 OK 2_object_stats_trigger.sql (265.67µs)19982026/09/20 16:24:29 goose: up to current file version: 219992026/09/20 16:24:29 OK 20251218171726_add_pins.sql (911.17µs)20002026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (20.2ms)20012026-09-20 16:24:29.266 UTC [73703] ERROR: relation "goose_db_version" does not exist at character 3620022026-09-20 16:24:29.266 UTC [73703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20032026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (32.12ms)20042026/09/20 16:24:29 OK 20260905000000_add_claims.sql (19.42ms)20052026/09/20 16:24:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.057678ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20062026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (6.73ms)20072026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000020082026/09/20 16:24:29 OK 20260905000000_add_claims.sql (16.04ms)20092026/09/20 16:24:29 OK 1_commit_pending_closure.sql (961.63µs)20102026/09/20 16:24:29 OK 2_object_stats_trigger.sql (355.33µs)20112026/09/20 16:24:29 goose: up to current file version: 220122026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (1.25ms)20132026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000020142026/09/20 16:24:29 OK 1_commit_pending_closure.sql (961.46µs)20152026/09/20 16:24:29 OK 2_object_stats_trigger.sql (208.92µs)20162026/09/20 16:24:29 goose: up to current file version: 22017--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2018 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2019 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2020 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2021=== CONT TestClientErrorHandling/InvalidAuthToken20222026/09/20 16:24:29 OK 20241026095416_initial_model.sql (21.27ms)20232026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (554.29µs)20242026/09/20 16:24:29 OK 20251218171726_add_pins.sql (9.97ms)20252026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (9.29ms)20262026/09/20 16:24:29 INFO Received cleanup request method=DELETE path=/api/pending_closures20272026/09/20 16:24:29 INFO Aborted multipart uploads count=120282026/09/20 16:24:29 OK 20260905000000_add_claims.sql (10.18ms)2029--- PASS: TestMultipartCleanup (1.23s)2030=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2031=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20322026/09/20 16:24:29 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]2033=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2034=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20352026/09/20 16:24:29 WARN Authentication failed token_preview=eyJhbGciOi...oCLxIAUgvA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2036=== CONT TestService_RequireScope_OIDC/builder_may_write2037=== CONT TestService_RequireScope_OIDC/static_token_may_admin2038=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2039=== CONT TestService_RequireScope_OIDC/writer_implies_read2040=== CONT TestService_RequireScope_OIDC/reader_may_read2041=== CONT TestService_RequireScope_OIDC/static_token_may_write2042=== CONT TestService_RequireScope_OIDC/ops_may_not_write2043=== CONT TestService_RequireScope_OIDC/reader_may_not_write2044=== CONT TestService_RequireScope_OIDC/ops_may_admin2045=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2046=== CONT TestServerTLSConfig/no_client_CA2047=== CONT TestServerTLSConfig/not_a_PEM_file2048--- PASS: TestService_AuthMiddleware_OIDC (1.83s)2049 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2050 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2051 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2052 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2053--- PASS: TestService_RequireScope_OIDC (1.68s)2054 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2061 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2062 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2063 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20642026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (15.46ms)20652026/09/20 16:24:29 goose: successfully migrated database to version: 202609200000002066=== CONT TestServerTLSConfig/missing_CA_file2067--- PASS: TestServerTLSConfig (0.00s)2068 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2069 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2070 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)20712026/09/20 16:24:29 OK 1_commit_pending_closure.sql (972.25µs)20722026/09/20 16:24:29 OK 2_object_stats_trigger.sql (209.13µs)20732026/09/20 16:24:29 goose: up to current file version: 220742026/09/20 16:24:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20752026/09/20 16:24:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2076--- PASS: TestService_NativeMTLS (1.08s)20772026/09/20 16:24:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02078=== NAME TestClientIntegration2079 client_integration_test.go:323: Objects in database after GC:2080 client_integration_test.go:323: Successfully deleted all objects with GC --force2081--- PASS: TestClientIntegration (3.94s)20822026/09/20 16:24:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.933909ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2083--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.17s)20842026-09-20 16:24:29.550 UTC [73706] ERROR: relation "goose_db_version" does not exist at character 3620852026-09-20 16:24:29.550 UTC [73706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20862026/09/20 16:24:29 OK 20241026095416_initial_model.sql (42.01ms)20872026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (982.17µs)20882026/09/20 16:24:29 OK 20251218171726_add_pins.sql (19.29ms)20892026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (11.82ms)20902026/09/20 16:24:29 OK 20260905000000_add_claims.sql (24.79ms)20912026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (22.03ms)20922026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000020932026/09/20 16:24:29 OK 1_commit_pending_closure.sql (13.2ms)20942026/09/20 16:24:29 OK 2_object_stats_trigger.sql (1.2ms)20952026/09/20 16:24:29 goose: up to current file version: 220962026-09-20 16:24:29.721 UTC [73707] ERROR: relation "goose_db_version" does not exist at character 3620972026-09-20 16:24:29.721 UTC [73707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20982026/09/20 16:24:29 OK 20241026095416_initial_model.sql (30.28ms)20992026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)21002026/09/20 16:24:29 OK 20251218171726_add_pins.sql (7.45ms)21012026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (7.94ms)21022026/09/20 16:24:29 OK 20260905000000_add_claims.sql (24.31ms)21032026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (7.94ms)21042026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000021052026/09/20 16:24:29 OK 1_commit_pending_closure.sql (1.37ms)21062026/09/20 16:24:29 OK 2_object_stats_trigger.sql (350.29µs)21072026/09/20 16:24:29 goose: up to current file version: 22108=== NAME TestNARDeduplicationMetadataUploadBug2109 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-73286-1319645990/TestNARDeduplicationMetadataUploadBug3434376008/001/store/x6nwc1f19x7rqdnj757m9szp2nq9lid2-file1.txt21102026/09/20 16:24:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21112026/09/20 16:24:29 WARN mTLS auth: bound subjects configured but subject DN unavailable21122026/09/20 16:24:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2113--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.39s)21142026-09-20 16:24:29.873 UTC [73711] ERROR: relation "goose_db_version" does not exist at character 3621152026-09-20 16:24:29.873 UTC [73711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21162026/09/20 16:24:29 OK 20241026095416_initial_model.sql (20.28ms)21172026/09/20 16:24:29 OK 20251210153512_drop_unused_gin_index.sql (421.17µs)21182026/09/20 16:24:29 OK 20251218171726_add_pins.sql (5.48ms)21192026/09/20 16:24:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21202026/09/20 16:24:29 OK 20260628120000_add_object_size_and_stats.sql (7.37ms)21212026/09/20 16:24:29 OK 20260905000000_add_claims.sql (4.69ms)21222026/09/20 16:24:29 OK 20260920000000_drop_claims.sql (7.55ms)21232026/09/20 16:24:29 goose: successfully migrated database to version: 2026092000000021242026/09/20 16:24:29 OK 1_commit_pending_closure.sql (818.58µs)21252026/09/20 16:24:29 OK 2_object_stats_trigger.sql (223.71µs)21262026/09/20 16:24:29 goose: up to current file version: 221272026/09/20 16:24:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.113148ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21282026/09/20 16:24:29 INFO Received uploads request method=POST path=/api/pending_closures21292026/09/20 16:24:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21302026/09/20 16:24:29 INFO Uploading x6nwc1f19x7rqdnj757m9szp2nq9lid2-file1.txt (160B)2131--- PASS: TestService_healthCheckHandler (1.11s)21322026/09/20 16:24:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21332026/09/20 16:24:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21342026/09/20 16:24:29 INFO Signed narinfos id=1 count=121352026/09/20 16:24:29 WARN Failed to register uploaded object key=x6nwc1f19x7rqdnj757m9szp2nq9lid2.ls error="server returned 404: 404 page not found\n"21362026/09/20 16:24:29 INFO Uploading 1 narinfos21372026/09/20 16:24:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21382026/09/20 16:24:29 WARN Failed to register uploaded object key=x6nwc1f19x7rqdnj757m9szp2nq9lid2.narinfo error="server returned 404: 404 page not found\n"21392026/09/20 16:24:29 INFO Completed upload id=121402026/09/20 16:24:29 INFO Upload complete. (111ms)2141=== NAME TestNARDeduplicationMetadataUploadBug2142 metadata_upload_test.go:54: Retrieved narinfo from S3:2143 StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestNARDeduplicationMetadataUploadBug3434376008/001/store/x6nwc1f19x7rqdnj757m9szp2nq9lid2-file1.txt2144 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2145 Compression: zstd2146 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2147 NarSize: 1602148 References: 2149 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2150 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2151 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2152 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2153 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-73286-1319645990/TestNARDeduplicationMetadataUploadBug3434376008/001/store/jxssz638bs0b2x2lf6n62ymsq669incs-file2.txt21542026/09/20 16:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21552026/09/20 16:24:30 INFO Received uploads request method=POST path=/api/pending_closures21562026/09/20 16:24:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21572026/09/20 16:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21582026/09/20 16:24:30 INFO Signed narinfos id=2 count=121592026/09/20 16:24:30 INFO Uploading 1 narinfos21602026/09/20 16:24:30 WARN Failed to register uploaded object key=jxssz638bs0b2x2lf6n62ymsq669incs.ls error="server returned 404: 404 page not found\n"21612026/09/20 16:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21622026/09/20 16:24:30 WARN Failed to register uploaded object key=jxssz638bs0b2x2lf6n62ymsq669incs.narinfo error="server returned 404: 404 page not found\n"21632026/09/20 16:24:30 INFO Completed upload id=221642026/09/20 16:24:30 INFO Upload complete. (71ms)2165 metadata_upload_test.go:76: Retrieved narinfo from S3:2166 StorePath: /nix/var/nix/builds/nix-73286-1319645990/TestNARDeduplicationMetadataUploadBug3434376008/001/store/jxssz638bs0b2x2lf6n62ymsq669incs-file2.txt2167 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2168 Compression: zstd2169 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2170 NarSize: 1602171 References: 2172 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2173 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2174 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2175 {"version":1,"root":{"type":"regular","size":44}}2176--- PASS: TestNARDeduplicationMetadataUploadBug (1.78s)21772026/09/20 16:24:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21782026/09/20 16:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21792026/09/20 16:24:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21802026/09/20 16:24:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.593790188s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21812026/09/20 16:24:32 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-config21822026/09/20 16:24:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.565343ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21832026/09/20 16:24:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.791621ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/09/20 16:24:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=792.861741ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/09/20 16:24:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.676616242s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21862026/09/20 16:24:35 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"21872026/09/20 16:24:35 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_closures21882026/09/20 16:24:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.109238ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21892026/09/20 16:24:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.149277ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21902026/09/20 16:24:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.458139ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21912026/09/20 16:24:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.628094379s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2192--- PASS: TestClientErrorHandling (0.00s)2193 --- PASS: TestClientErrorHandling/InvalidStorePath (1.03s)2194 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.95s)2195 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.69s)2196PASS2197{"timestamp":"2026-09-20T16:24:38.739384Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59230","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(5)"}21982026-09-20 16:24:38.840 UTC [73323] LOG: received smart shutdown request21992026-09-20 16:24:38.841 UTC [73323] LOG: background worker "logical replication launcher" (PID 73334) exited with exit code 122002026-09-20 16:24:38.848 UTC [73328] LOG: shutting down22012026-09-20 16:24:38.848 UTC [73328] LOG: checkpoint starting: shutdown immediate22022026-09-20 16:24:39.919 UTC [73328] LOG: checkpoint complete: wrote 12981 buffers (79.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.728 s, sync=0.308 s, total=1.071 s; sync files=18404, longest=0.001 s, average=0.001 s; distance=255510 kB, estimate=255510 kB; lsn=0/11112980, redo lsn=0/1111298022032026-09-20 16:24:39.923 UTC [73323] LOG: database system is shut down2204Running OIDC tests...2205=== RUN TestGlobMatch2206=== PAUSE TestGlobMatch2207=== RUN TestAudienceForIssuer2208=== PAUSE TestAudienceForIssuer2209=== RUN TestValidateToken_ValidToken2210=== PAUSE TestValidateToken_ValidToken2211=== RUN TestValidateToken_WrongAudience2212=== PAUSE TestValidateToken_WrongAudience2213=== RUN TestValidateToken_Expired2214=== PAUSE TestValidateToken_Expired2215=== RUN TestValidateToken_BoundClaimsMismatch2216=== PAUSE TestValidateToken_BoundClaimsMismatch2217=== RUN TestValidateToken_BoundSubjectMismatch2218=== PAUSE TestValidateToken_BoundSubjectMismatch2219=== RUN TestValidateToken_MultipleProviders2220=== PAUSE TestValidateToken_MultipleProviders2221=== RUN TestValidateToken_NoMatchingProvider2222=== PAUSE TestValidateToken_NoMatchingProvider2223=== RUN TestValidateToken_KubernetesServiceAccount2224=== PAUSE TestValidateToken_KubernetesServiceAccount2225=== RUN TestNewValidator_KubernetesRequiresCA2226=== PAUSE TestNewValidator_KubernetesRequiresCA2227=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2228=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2229=== RUN TestScopes_LegacyProviderDefaultsToWrite2230=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2231=== RUN TestScopes_Rules2232=== PAUSE TestScopes_Rules2233=== RUN TestScopes_ConfigValidation2234=== PAUSE TestScopes_ConfigValidation2235=== CONT TestGlobMatch2236=== RUN TestGlobMatch/foo_foo2237=== PAUSE TestGlobMatch/foo_foo2238=== RUN TestGlobMatch/foo_bar2239=== PAUSE TestGlobMatch/foo_bar2240=== RUN TestGlobMatch/*_2241=== CONT TestScopes_LegacyProviderDefaultsToWrite2242=== CONT TestValidateToken_NoMatchingProvider2243=== CONT TestScopes_Rules2244=== CONT TestValidateToken_Expired2245=== CONT TestValidateToken_MultipleProviders2246=== CONT TestValidateToken_BoundSubjectMismatch2247=== CONT TestValidateToken_BoundClaimsMismatch2248=== CONT TestNewValidator_KubernetesRequiresCA2249=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2250=== PAUSE TestGlobMatch/*_2251=== RUN TestGlobMatch/*_anything2252=== PAUSE TestGlobMatch/*_anything2253=== RUN TestGlobMatch/foo*_foo2254=== PAUSE TestGlobMatch/foo*_foo2255=== RUN TestGlobMatch/foo*_foobar2256=== PAUSE TestGlobMatch/foo*_foobar2257=== RUN TestGlobMatch/foo*_bar2258=== PAUSE TestGlobMatch/foo*_bar2259=== RUN TestGlobMatch/*bar_bar2260=== PAUSE TestGlobMatch/*bar_bar2261=== RUN TestGlobMatch/*bar_foobar2262=== PAUSE TestGlobMatch/*bar_foobar2263=== RUN TestGlobMatch/*bar_foo2264=== PAUSE TestGlobMatch/*bar_foo2265=== RUN TestGlobMatch/foo*bar_foobar2266=== PAUSE TestGlobMatch/foo*bar_foobar2267=== RUN TestGlobMatch/foo*bar_foo123bar2268=== PAUSE TestGlobMatch/foo*bar_foo123bar2269=== RUN TestGlobMatch/foo*bar_foobarbaz2270=== PAUSE TestGlobMatch/foo*bar_foobarbaz2271=== RUN TestGlobMatch/*/*_foo/bar2272=== PAUSE TestGlobMatch/*/*_foo/bar2273=== RUN TestGlobMatch/*/*_foo2274=== PAUSE TestGlobMatch/*/*_foo2275=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2276=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2277=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02278=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02279=== RUN TestGlobMatch/refs/*/main_refs/heads/main2280=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2281=== RUN TestGlobMatch/fo?_foo2282=== PAUSE TestGlobMatch/fo?_foo2283=== RUN TestGlobMatch/fo?_fo2284=== PAUSE TestGlobMatch/fo?_fo2285=== RUN TestGlobMatch/fo?_fooo2286=== PAUSE TestGlobMatch/fo?_fooo2287=== RUN TestGlobMatch/?oo_foo2288=== PAUSE TestGlobMatch/?oo_foo2289=== RUN TestGlobMatch/?oo_boo2290=== PAUSE TestGlobMatch/?oo_boo2291=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2292=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2293=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2294=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2295=== CONT TestValidateToken_ValidToken22962026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59404/oidc22972026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59407/oidc22982026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59414/oidc22992026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59408/oidc23002026/09/20 16:24:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59410/oidc23012026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59406/oidc23022026/09/20 16:24:40 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323032026/09/20 16:24:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59405/oidc23042026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59409/oidc2305--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2306--- PASS: TestValidateToken_ValidToken (0.01s)2307--- PASS: TestValidateToken_Expired (0.01s)2308=== CONT TestAudienceForIssuer2309--- PASS: TestAudienceForIssuer (0.00s)2310=== CONT TestScopes_ConfigValidation2311=== CONT TestValidateToken_KubernetesServiceAccount23122026/09/20 16:24:40 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59412/oidc2313=== CONT TestValidateToken_WrongAudience2314--- PASS: TestScopes_ConfigValidation (0.00s)2315=== CONT TestGlobMatch/foo_foo2316=== CONT TestGlobMatch/*/*_foo/bar2317=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2318=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2319=== CONT TestGlobMatch/?oo_boo2320=== CONT TestGlobMatch/?oo_foo2321=== CONT TestGlobMatch/fo?_fooo2322=== CONT TestGlobMatch/fo?_fo2323=== CONT TestGlobMatch/fo?_foo2324=== CONT TestGlobMatch/refs/*/main_refs/heads/main2325=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02326=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2327=== CONT TestGlobMatch/*/*_foo2328=== CONT TestGlobMatch/*bar_bar2329=== CONT TestGlobMatch/foo*bar_foobarbaz2330=== CONT TestGlobMatch/foo*bar_foo123bar2331=== CONT TestGlobMatch/*bar_foo2332=== CONT TestGlobMatch/foo*bar_foobar2333=== CONT TestGlobMatch/*bar_foobar2334=== CONT TestGlobMatch/foo*_foo2335=== CONT TestGlobMatch/foo*_bar2336=== CONT TestGlobMatch/foo*_foobar2337=== CONT TestGlobMatch/*_2338=== CONT TestGlobMatch/*_anything2339=== CONT TestGlobMatch/foo_bar2340--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2341--- PASS: TestGlobMatch (0.00s)2342 --- PASS: TestGlobMatch/foo_foo (0.00s)2343 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2344 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2345 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2346 --- PASS: TestGlobMatch/?oo_boo (0.00s)2347 --- PASS: TestGlobMatch/?oo_foo (0.00s)2348 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2349 --- PASS: TestGlobMatch/fo?_fo (0.00s)2350 --- PASS: TestGlobMatch/fo?_foo (0.00s)2351 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2352 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2353 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2354 --- PASS: TestGlobMatch/*/*_foo (0.00s)2355 --- PASS: TestGlobMatch/*bar_bar (0.00s)2356 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2357 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2358 --- PASS: TestGlobMatch/*bar_foo (0.00s)2359 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2360 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2361 --- PASS: TestGlobMatch/foo*_foo (0.00s)2362 --- PASS: TestGlobMatch/foo*_bar (0.00s)2363 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2364 --- PASS: TestGlobMatch/*_ (0.00s)2365 --- PASS: TestGlobMatch/*_anything (0.00s)2366 --- PASS: TestGlobMatch/foo_bar (0.00s)23672026/09/20 16:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59428/oidc2368--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2369--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2370--- PASS: TestValidateToken_MultipleProviders (0.01s)23712026/09/20 16:24:40 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:594262372--- PASS: TestScopes_Rules (0.02s)2373--- PASS: TestValidateToken_WrongAudience (0.01s)2374--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)23752026/09/20 16:24:40 http: TLS handshake error from 127.0.0.1:59423: remote error: tls: bad certificate2376--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2377--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2378PASS2379Running hook tests...2380=== RUN TestSendPathsEmpty2381=== PAUSE TestSendPathsEmpty2382=== RUN TestQueueEnqueueAndFetch2383=== PAUSE TestQueueEnqueueAndFetch2384=== RUN TestQueueDeduplication2385=== PAUSE TestQueueDeduplication2386=== RUN TestQueueRemove2387=== PAUSE TestQueueRemove2388=== RUN TestQueueFetchBatchLimit2389=== PAUSE TestQueueFetchBatchLimit2390=== RUN TestQueueRetryMovesToBack2391=== PAUSE TestQueueRetryMovesToBack2392=== RUN TestQueueFetchRemoveLifecycle2393=== PAUSE TestQueueFetchRemoveLifecycle2394=== RUN TestQueueConcurrentWriters2395=== PAUSE TestQueueConcurrentWriters2396=== RUN TestQueueRemoveLargeClosure2397=== PAUSE TestQueueRemoveLargeClosure2398=== RUN TestServerClientIntegration2399=== PAUSE TestServerClientIntegration2400=== RUN TestServerQueueError2401=== PAUSE TestServerQueueError2402=== RUN TestGetListenerSocketActivation2403 server_test.go:210: === RUN TestGetListenerSocketActivation2404 --- PASS: TestGetListenerSocketActivation (0.00s)2405 PASS2406 2407--- PASS: TestGetListenerSocketActivation (0.01s)2408=== RUN TestDrainIsolatesPoisonPath2409=== PAUSE TestDrainIsolatesPoisonPath2410=== RUN TestRunNotBlockedByPoisonHead2411=== PAUSE TestRunNotBlockedByPoisonHead2412=== RUN TestDrainGivesUpWhenServerDown2413=== PAUSE TestDrainGivesUpWhenServerDown2414=== RUN TestFailedPathPrunedByLaterClosure2415=== PAUSE TestFailedPathPrunedByLaterClosure2416=== RUN TestWorkerUploadsAndRemoves2417=== PAUSE TestWorkerUploadsAndRemoves2418=== RUN TestWorkerSkipsGCdPaths2419=== PAUSE TestWorkerSkipsGCdPaths2420=== RUN TestWorkerPrunesClosureDeps2421=== PAUSE TestWorkerPrunesClosureDeps2422=== RUN TestDrainTimeout2423=== PAUSE TestDrainTimeout2424=== CONT TestSendPathsEmpty2425=== CONT TestServerQueueError2426--- PASS: TestSendPathsEmpty (0.00s)2427=== CONT TestQueueRetryMovesToBack2428=== CONT TestQueueFetchBatchLimit2429=== CONT TestQueueRemove2430=== CONT TestQueueDeduplication2431=== CONT TestQueueEnqueueAndFetch2432=== CONT TestQueueRemoveLargeClosure2433=== CONT TestServerClientIntegration2434=== CONT TestQueueConcurrentWriters2435=== CONT TestQueueFetchRemoveLifecycle24362026/09/20 16:24:41 ERROR Failed to queue paths error="permission denied" count=12437--- PASS: TestServerClientIntegration (0.00s)2438=== CONT TestWorkerUploadsAndRemoves2439--- PASS: TestServerQueueError (0.00s)2440=== CONT TestDrainTimeout24412026/09/20 16:24:41 INFO Upload queue status pending=224422026/09/20 16:24:41 INFO Uploading batch count=22443--- PASS: TestQueueRetryMovesToBack (0.01s)2444=== CONT TestWorkerPrunesClosureDeps24452026/09/20 16:24:41 INFO Uploading batch count=22446--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2447=== CONT TestWorkerSkipsGCdPaths2448--- PASS: TestQueueRemove (0.01s)2449=== CONT TestDrainGivesUpWhenServerDown2450--- PASS: TestQueueFetchBatchLimit (0.01s)2451=== CONT TestFailedPathPrunedByLaterClosure2452--- PASS: TestQueueEnqueueAndFetch (0.01s)2453=== CONT TestRunNotBlockedByPoisonHead2454--- PASS: TestQueueDeduplication (0.01s)2455=== CONT TestDrainIsolatesPoisonPath24562026/09/20 16:24:41 INFO Upload queue status pending=224572026/09/20 16:24:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-73286-1319645990/TestWorkerSkipsGCdPaths4151916123/002/nonexistent24582026/09/20 16:24:41 INFO Uploading batch count=124592026/09/20 16:24:41 INFO Upload queue status pending=224602026/09/20 16:24:41 INFO Uploading batch count=124612026/09/20 16:24:41 INFO Uploading batch count=424622026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=424632026/09/20 16:24:41 INFO Upload queue status pending=324642026/09/20 16:24:41 INFO Uploading batch count=124652026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainIsolatesPoisonPath316718659/002/bbb24662026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=124672026/09/20 16:24:41 INFO Uploading batch count=124682026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=124692026/09/20 16:24:41 INFO Uploading batch count=124702026/09/20 16:24:41 INFO Uploading batch count=124712026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=124722026/09/20 16:24:41 INFO Uploading batch count=124732026/09/20 16:24:41 INFO Uploading batch count=124742026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=124752026/09/20 16:24:41 INFO Uploading batch count=224762026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=224772026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/a24782026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/b24792026/09/20 16:24:41 INFO Uploading batch count=124802026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=124812026/09/20 16:24:41 ERROR Drain finished with paths left in queue remaining=124822026/09/20 16:24:41 INFO Uploading batch count=224832026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=224842026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/c2485--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24862026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/d24872026/09/20 16:24:41 INFO Uploading batch count=224882026/09/20 16:24:41 ERROR Upload failed error="upload failed" count=224892026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/e24902026/09/20 16:24:41 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-73286-1319645990/TestDrainGivesUpWhenServerDown3342380545/002/f24912026/09/20 16:24:41 ERROR Drain finished with paths left in queue remaining=102492--- PASS: TestDrainIsolatesPoisonPath (0.01s)2493--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2494--- PASS: TestWorkerUploadsAndRemoves (0.03s)2495--- PASS: TestWorkerSkipsGCdPaths (0.02s)2496--- PASS: TestWorkerPrunesClosureDeps (0.02s)2497--- PASS: TestQueueRemoveLargeClosure (0.06s)2498--- PASS: TestQueueConcurrentWriters (0.15s)24992026/09/20 16:24:41 ERROR Upload failed error="context deadline exceeded" count=225002026/09/20 16:24:41 ERROR Drain finished with paths left in queue remaining=42501--- PASS: TestDrainTimeout (0.21s)25022026/09/20 16:24:42 INFO Uploading batch count=125032026/09/20 16:24:42 INFO Uploading batch count=125042026/09/20 16:24:42 INFO Uploading batch count=125052026/09/20 16:24:42 ERROR Upload failed error="upload failed" count=125062026/09/20 16:24:42 INFO Uploading batch count=125072026/09/20 16:24:42 ERROR Upload failed error="upload failed" count=125082026/09/20 16:24:42 INFO Uploading batch count=125092026/09/20 16:24:42 ERROR Upload failed error="upload failed" count=125102026/09/20 16:24:42 INFO Uploading batch count=125112026/09/20 16:24:42 ERROR Upload failed error="upload failed" count=125122026/09/20 16:24:42 ERROR Drain finished with paths left in queue remaining=12513--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2514PASS